File: file_stats.cpp

package info (click to toggle)
0ad 0.27.1-3
  • links: PTS, VCS
  • area: main
  • in suites: forky, sid
  • size: 173,296 kB
  • sloc: cpp: 194,003; javascript: 19,098; ansic: 15,066; python: 6,328; sh: 1,699; perl: 1,575; java: 533; xml: 482; php: 192; makefile: 99
file content (313 lines) | stat: -rw-r--r-- 8,427 bytes parent folder | download | duplicates (6)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
/* Copyright (C) 2010 Wildfire Games.
 *
 * Permission is hereby granted, free of charge, to any person obtaining
 * a copy of this software and associated documentation files (the
 * "Software"), to deal in the Software without restriction, including
 * without limitation the rights to use, copy, modify, merge, publish,
 * distribute, sublicense, and/or sell copies of the Software, and to
 * permit persons to whom the Software is furnished to do so, subject to
 * the following conditions:
 *
 * The above copyright notice and this permission notice shall be included
 * in all copies or substantial portions of the Software.
 *
 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
 * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
 * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.
 * IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY
 * CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT,
 * TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE
 * SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
 */

/*
 * gathers statistics from all file modules.
 */

#include "precompiled.h"
#include "lib/file/common/file_stats.h"

#include <set>

#include "lib/timer.h"

#if FILE_STATS_ENABLED

// vfs
static size_t vfs_files;
static double vfs_size_total;
static double vfs_init_elapsed_time;

// file
static size_t unique_names;
static size_t unique_name_len_total;
static size_t open_files_cur, open_files_max;	// total = opened_files.size()

// file_buf
static size_t extant_bufs_cur, extant_bufs_max, extant_bufs_total;
static double buf_size_total, buf_aligned_size_total;

// file_io
static size_t user_ios;
static double user_io_size_total;
static double io_actual_size_total[FI_MAX_IDX][2];
static double io_elapsed_time[FI_MAX_IDX][2];
static double io_process_time_total;
static size_t io_seeks;

// file_cache
static size_t cache_count[2];
static double cache_size_total[2];
static size_t conflict_misses;
//static double conflict_miss_size_total;	// JW: currently not used nor computed
static size_t block_cache_count[2];

// archive builder
static size_t ab_connection_attempts;	// total number of trace entries
static size_t ab_repeated_connections;	// how many of these were not unique


// convenience functions for measuring elapsed time in an interval.
// by exposing start/finish calls, we avoid callers from querying
// timestamps when stats are disabled.
static double start_time;
static void timer_start(double* start_time_storage = &start_time)
{
	// make sure no measurement is currently active
	// (since start_time is shared static storage)
	ENSURE(*start_time_storage == 0.0);
	*start_time_storage = timer_Time();
}
static double timer_reset(double* start_time_storage = &start_time)
{
	double elapsed = timer_Time() - *start_time_storage;
	*start_time_storage = 0.0;
	return elapsed;
}

//-----------------------------------------------------------------------------

//
// vfs
//

void stats_vfs_file_add(size_t file_size)
{
	vfs_files++;
	vfs_size_total += file_size;
}

void stats_vfs_file_remove(size_t file_size)
{
	vfs_files--;
	vfs_size_total -= file_size;
}

// stats_vfs_init_* are currently unused
void stats_vfs_init_start()
{
	timer_start();
}

void stats_vfs_init_finish()
{
	vfs_init_elapsed_time += timer_reset();
}


//
// file
//

void stats_unique_name(size_t name_len)
{
	unique_names++;
	unique_name_len_total += name_len;
}


void stats_open()
{
	open_files_cur++;
	open_files_max = std::max(open_files_max, open_files_cur);

	// could also use a set to determine unique files that have been opened
}

void stats_close()
{
	ENSURE(open_files_cur > 0);
	open_files_cur--;
}


//
// file_buf
//

void stats_buf_alloc(size_t size, size_t alignedSize)
{
	extant_bufs_cur++;
	extant_bufs_max = std::max(extant_bufs_max, extant_bufs_cur);
	extant_bufs_total++;

	buf_size_total += size;
	buf_aligned_size_total += alignedSize;
}

void stats_buf_free()
{
	ENSURE(extant_bufs_cur > 0);
	extant_bufs_cur--;
}

void stats_buf_ref()
{
	extant_bufs_cur++;
}


//
// file_io
//

void stats_io_user_request(size_t user_size)
{
	user_ios++;
	user_io_size_total += user_size;
}

ScopedIoMonitor::ScopedIoMonitor()
{
	m_startTime = 0.0;
	timer_start(&m_startTime);
}

ScopedIoMonitor::~ScopedIoMonitor()
{
	// note: we can only bill IOs that have succeeded :S
	timer_reset(&m_startTime);
}

void ScopedIoMonitor::NotifyOfSuccess(FileIOImplentation fi, int opcode, off_t size)
{
	ENSURE(fi < FI_MAX_IDX);
	ENSURE(opcode == LIO_READ || opcode == LIO_WRITE);

	io_actual_size_total[fi][opcode == LIO_WRITE] += size;
	io_elapsed_time[fi][opcode == LIO_WRITE] += timer_reset(&m_startTime);
}


void stats_cb_start()
{
	timer_start();
}

void stats_cb_finish()
{
	io_process_time_total += timer_reset();
}


void stats_block_cache(CacheRet cr)
{
	ENSURE(cr == CR_HIT || cr == CR_MISS);
	block_cache_count[cr]++;
}


//
// archive builder
//

void stats_ab_connection(bool already_exists)
{
	ab_connection_attempts++;
	if(already_exists)
		ab_repeated_connections++;
}


//-----------------------------------------------------------------------------

template<typename T> int percent(T num, T divisor)
{
	if(!divisor)
		return 0;
	return (int)(100*num / divisor);
}

void file_stats_dump()
{
	if(!debug_filter_allows("FILE_STATS|"))
		return;

	const double KB = 1e3; const double MB = 1e6; const double ms = 1e-3;

	debug_printf("--------------------------------------------------------------------------------\n");
	debug_printf("File statistics:\n");

	// note: we split the reports into several debug_printfs for clarity;
	// this is necessary anyway due to fixed-size buffer.

	debug_printf(
		L"\nvfs:\n"
		L"Total files: %lu (%g MB)\n"
		L"Init/mount time: %g ms\n",
		(unsigned long)vfs_files, vfs_size_total/MB,
		vfs_init_elapsed_time/ms
	);

	debug_printf(
		L"\nfile:\n"
		L"Total names: %lu (%lu KB)\n"
		L"Max. concurrent: %lu; leaked: %lu.\n",
		(unsigned long)unique_names, (unsigned long)(unique_name_len_total/1000),
		(unsigned long)open_files_max, (unsigned long)open_files_cur
	);

	debug_printf(
		L"\nfile_buf:\n"
		L"Total buffers used: %lu (%g MB)\n"
		L"Max concurrent: %lu; leaked: %lu\n"
		L"Internal fragmentation: %d%%\n",
		(unsigned long)extant_bufs_total, buf_size_total/MB,
		(unsigned long)extant_bufs_max, (unsigned long)extant_bufs_cur,
		percent(buf_aligned_size_total-buf_size_total, buf_size_total)
	);

	debug_printf(
		L"\nfile_io:\n"
		L"Total user load requests: %lu (%g MB)\n"
		L"IO thoughput [MB/s; 0=never happened]:\n"
		L"  lowio: R=%.3g, W=%.3g\n"
		L"    aio: R=%.3g, W=%.3g\n"
		L"Average size = %g KB; seeks: %lu; total callback time: %g ms\n"
		L"Total data actually read from disk = %g MB\n",
		(unsigned long)user_ios, user_io_size_total/MB,
#define THROUGHPUT(impl, opcode) (io_elapsed_time[impl][opcode == LIO_WRITE] == 0.0)? 0.0 : (io_actual_size_total[impl][opcode == LIO_WRITE] / io_elapsed_time[impl][opcode == LIO_WRITE] / MB)
		THROUGHPUT(FI_LOWIO, LIO_READ), THROUGHPUT(FI_LOWIO, LIO_WRITE),
		THROUGHPUT(FI_AIO  , LIO_READ), THROUGHPUT(FI_AIO  , LIO_WRITE),
		user_io_size_total/user_ios/KB, (unsigned long)io_seeks, io_process_time_total/ms,
		(io_actual_size_total[FI_LOWIO][0]+io_actual_size_total[FI_AIO][0])/MB
	);

	debug_printf(
		L"\nfile_cache:\n"
		L"Hits: %lu (%g MB); misses %lu (%g MB); ratio: %u%%\n"
		L"Percent of requested bytes satisfied by cache: %u%%; non-compulsory misses: %lu (%u%% of misses)\n"
		L"Block hits: %lu; misses: %lu; ratio: %u%%\n",
		(unsigned long)cache_count[CR_HIT], cache_size_total[CR_HIT]/MB, (unsigned long)cache_count[CR_MISS], cache_size_total[CR_MISS]/MB, percent(cache_count[CR_HIT], cache_count[CR_HIT]+cache_count[CR_MISS]),
		percent(cache_size_total[CR_HIT], cache_size_total[CR_HIT]+cache_size_total[CR_MISS]), (unsigned long)conflict_misses, percent(conflict_misses, cache_count[CR_MISS]),
		(unsigned long)block_cache_count[CR_HIT], (unsigned long)block_cache_count[CR_MISS], percent(block_cache_count[CR_HIT], block_cache_count[CR_HIT]+block_cache_count[CR_MISS])
	);

	debug_printf(
		L"\nvfs_optimizer:\n"
		L"Total trace entries: %lu; repeated connections: %lu; unique files: %lu\n",
		(unsigned long)ab_connection_attempts, (unsigned long)ab_repeated_connections, (unsigned long)(ab_connection_attempts-ab_repeated_connections)
	);
}

#endif	// FILE_STATS_ENABLED