Line data Source code
1 1 : /**
2 : * @file log/stats.c
3 : *
4 : * @brief Statistics module
5 : *
6 : * All facilities to collect, gather, and dump statistics are implemented
7 : * in this module.
8 : *
9 : * SPDX-FileCopyrightText: 2008-2021 HPDCS Group <rootsim@googlegroups.com>
10 : * SPDX-License-Identifier: GPL-3.0-only
11 : */
12 : #include <log/stats.h>
13 :
14 : #include <arch/io.h>
15 : #include <arch/mem.h>
16 : #include <arch/timer.h>
17 : #include <core/arg_parse.h>
18 : #include <core/core.h>
19 :
20 : #include <assert.h>
21 : #include <inttypes.h>
22 : #include <memory.h>
23 : #include <stdarg.h>
24 : #include <stdatomic.h>
25 : #include <stdint.h>
26 : #include <stdio.h>
27 :
28 0 : #define STATS_BUFFER_ENTRIES (1024)
29 0 : #define STD_DEV_POWER_2_EXP 5
30 0 : #define STATS_MAX_STRLEN 32U
31 :
32 : /// A set of statistical values of a single metric
33 : /** The form of these values is designed for easier incremental updates */
34 1 : struct stats_measure {
35 : /// The count of events of this type
36 1 : uint64_t count;
37 : /// The mean time to complete an event multiplied by the events count
38 1 : uint64_t sum_t;
39 : /// The variance of the time to complete multiplied by the events count
40 1 : uint64_t var_t;
41 : };
42 :
43 : /// A container for statistics in a logical time period
44 1 : struct stats_thread {
45 : /// Real elapsed time in microseconds from simulation beginning
46 1 : uint64_t rt;
47 : /// The array of statistics taken in the period
48 : struct stats_measure s[STATS_COUNT];
49 : };
50 :
51 0 : struct stats_node {
52 : /// The gvt value
53 1 : simtime_t gvt;
54 : /// The size in bytes of the resident set
55 1 : uint64_t rss;
56 : };
57 :
58 0 : struct stats_glob {
59 : /// The number of threads in this node
60 1 : uint64_t threads_count;
61 : /// The maximum size in bytes of the resident set
62 1 : uint64_t max_rss;
63 : /// When stats global init has been called
64 1 : uint64_t glob_init_rt;
65 : /// The latest ts before having to aggregate stats
66 1 : uint64_t glob_fini_rt;
67 : /// The timestamps of the relevant simulation life-cycle events
68 1 : uint64_t timestamps[STATS_GLOBAL_COUNT];
69 : };
70 :
71 : static_assert(sizeof(struct stats_measure) == 24 &&
72 : sizeof(struct stats_thread) == 8 + 24 * STATS_COUNT &&
73 : sizeof(struct stats_node) == 16 &&
74 : sizeof(struct stats_glob) == 32 + 8 * (STATS_GLOBAL_COUNT),
75 : "structs aren't naturally packed, parsing may be difficult");
76 :
77 : /// The statistics names, used to fill in the header of the final csv
78 1 : const char * const s_names[] = {
79 : [STATS_ROLLBACK] = "rollbacks",
80 : [STATS_GVT] = "gvt",
81 : [STATS_MSG_SILENT] = "silent messages",
82 : [STATS_MSG_PROCESSED] = "processed messages"
83 : };
84 :
85 0 : static timer_uint sim_start_ts;
86 : static struct stats_glob stats_glob_cur;
87 :
88 0 : static FILE *stats_node_tmp;
89 0 : static FILE **stats_tmps;
90 0 : static __thread struct stats_thread stats_cur;
91 :
92 0 : static __thread timer_uint last_ts[STATS_COUNT];
93 :
94 0 : static void file_write_chunk(FILE *f, const void *data, size_t data_size)
95 : {
96 : if (unlikely(fwrite(data, data_size, 1, f) != 1))
97 : log_log(LOG_ERROR, "Error during disk write!");
98 : }
99 :
100 0 : static void *file_memory_load(FILE *f, int64_t *f_size_p)
101 : {
102 : fseek(f, 0, SEEK_END);
103 : long f_size = ftell(f); // Fails horribly for files bigger than 2 GB
104 : fseek(f, 0, SEEK_SET);
105 : void *ret = mm_alloc(f_size);
106 : if (fread(ret, f_size, 1, f) != 1) {
107 : mm_free(ret);
108 : *f_size_p = 0;
109 : return NULL;
110 : }
111 : *f_size_p = f_size;
112 : return ret;
113 : }
114 :
115 : /**
116 : * @brief A version of fopen() which accepts a printf style format string
117 : * @param open_type a string which controls how the file is opened (see fopen())
118 : * @param fmt the file name expressed as a printf style format string
119 : * @param ... the list of additional arguments used in @a fmt (see printf())
120 : */
121 1 : static FILE *file_open(const char *open_type, const char *fmt, ...)
122 : {
123 : va_list args, args_cp;
124 : va_start(args, fmt);
125 : va_copy(args_cp, args);
126 :
127 : size_t l = vsnprintf(NULL, 0, fmt, args_cp) + 1;
128 : va_end(args_cp);
129 :
130 : char *f_name = mm_alloc(l);
131 : vsnprintf(f_name, l, fmt, args);
132 : va_end(args);
133 :
134 : FILE *ret = fopen(f_name, open_type);
135 : if (ret == NULL)
136 : log_log(LOG_ERROR, "Unable to open \"%s\" in %s mode", f_name,
137 : open_type);
138 :
139 : mm_free(f_name);
140 : return ret;
141 : }
142 :
143 : /**
144 : * @brief Initializes the internal timer used to take accurate measurements
145 : */
146 1 : void stats_global_time_start(void)
147 : {
148 : sim_start_ts = timer_new();
149 : }
150 :
151 : /**
152 : * @brief Initializes the internal timer used to take accurate measurements
153 : */
154 1 : void stats_global_time_take(enum stats_global_time this_stat)
155 : {
156 : stats_glob_cur.timestamps[this_stat] = timer_value(sim_start_ts);
157 : }
158 :
159 : /**
160 : * @brief Initializes the stats subsystem in the node
161 : */
162 1 : void stats_global_init(void)
163 : {
164 : stats_glob_cur.glob_init_rt = timer_value(sim_start_ts);
165 : stats_glob_cur.threads_count = n_threads;
166 : if (mem_stat_setup() < 0)
167 : log_log(LOG_ERROR, "Unable to extract memory statistics!");
168 :
169 : stats_node_tmp = io_file_tmp_get();
170 : setvbuf(stats_node_tmp, NULL, _IOFBF,
171 : STATS_BUFFER_ENTRIES * sizeof(struct stats_node));
172 :
173 : stats_tmps = mm_alloc(n_threads * sizeof(*stats_tmps));
174 : }
175 :
176 : /**
177 : * @brief Initializes the stats subsystem in the current thread
178 : */
179 1 : void stats_init(void)
180 : {
181 : stats_tmps[rid] = io_file_tmp_get();
182 : setvbuf(stats_tmps[rid], NULL, _IOFBF,
183 : STATS_BUFFER_ENTRIES * sizeof(stats_cur));
184 : }
185 :
186 : #ifdef ROOTSIM_MPI
187 :
188 0 : static void stats_files_receive(FILE *o)
189 : {
190 : for (nid_t j = 1; j < n_nodes; ++j) {
191 : int buf_size;
192 : struct stats_glob *sg_p = mpi_blocking_data_rcv(&buf_size, j);
193 : file_write_chunk(o, sg_p, buf_size);
194 : uint64_t iters = sg_p->threads_count + 1; // +1 for node stats
195 : mm_free(sg_p);
196 :
197 : for (uint64_t i = 0; i < iters; ++i) {
198 : void *buf = mpi_blocking_data_rcv(&buf_size, j);
199 : int64_t f_size = buf_size;
200 : file_write_chunk(o, &f_size, sizeof(f_size));
201 : file_write_chunk(o, buf, buf_size);
202 : mm_free(buf);
203 : }
204 : }
205 : }
206 :
207 0 : static void stats_files_send(void)
208 : {
209 : stats_glob_cur.max_rss = mem_stat_rss_max_get();
210 : stats_glob_cur.glob_fini_rt = timer_value(sim_start_ts);
211 : mpi_blocking_data_send(&stats_glob_cur, sizeof(stats_glob_cur), 0);
212 :
213 : int64_t f_size;
214 : void *f_buf = file_memory_load(stats_node_tmp, &f_size);
215 : f_size = min(INT_MAX, f_size);
216 : mpi_blocking_data_send(f_buf, f_size, 0);
217 : mm_free(f_buf);
218 :
219 : for (rid_t i = 0; i < n_threads; ++i) {
220 : f_buf = file_memory_load(stats_tmps[i], &f_size);
221 : f_size = min(INT_MAX, f_size);
222 : mpi_blocking_data_send(f_buf, f_size, 0);
223 : mm_free(f_buf);
224 : }
225 : }
226 :
227 : #endif
228 :
229 0 : static void stats_file_final_write(FILE *o)
230 : {
231 : uint16_t endian_check = 61455U; // 0xFOOF
232 : file_write_chunk(o, &endian_check, sizeof(endian_check));
233 :
234 : int64_t n = STATS_COUNT;
235 : file_write_chunk(o, &n, sizeof(n));
236 : for (int i = 0; i < STATS_COUNT; ++i) {
237 : size_t l = min(strlen(s_names[i]), STATS_MAX_STRLEN);
238 : file_write_chunk(o, s_names[i], l);
239 : unsigned char nul = 0;
240 : for (; l < STATS_MAX_STRLEN; ++l)
241 : file_write_chunk(o, &nul, 1);
242 : }
243 :
244 : n = n_nodes;
245 : file_write_chunk(o, &n, sizeof(n));
246 :
247 : stats_glob_cur.max_rss = mem_stat_rss_max_get();
248 : stats_glob_cur.glob_fini_rt = timer_value(sim_start_ts);
249 : file_write_chunk(o, &stats_glob_cur, sizeof(stats_glob_cur));
250 :
251 : int64_t buf_size;
252 : void *buf = file_memory_load(stats_node_tmp, &buf_size);
253 : file_write_chunk(o, &buf_size, sizeof(buf_size));
254 : file_write_chunk(o, buf, buf_size);
255 : mm_free(buf);
256 :
257 : for (rid_t i = 0; i < n_threads; ++i) {
258 : buf = file_memory_load(stats_tmps[i], &buf_size);
259 : file_write_chunk(o, &buf_size, sizeof(buf_size));
260 : file_write_chunk(o, buf, buf_size);
261 : mm_free(buf);
262 : }
263 : }
264 :
265 : /**
266 : * @brief Finalizes the stats subsystem in the node
267 : *
268 : * When finalizing this subsystem the master node formats and dumps his
269 : * statistics from his temporary files onto the final csv. Then, in a
270 : * distributed setting, he receives the slaves temporary files, formatting and
271 : * dumping their statistics as well.
272 : */
273 1 : void stats_global_fini(void)
274 : {
275 : #ifdef ROOTSIM_MPI
276 : mpi_node_barrier();
277 : if (nid) {
278 : stats_files_send();
279 : return;
280 : }
281 : #endif
282 : FILE *o = file_open("w", "%s_stats.bin", arg_parse_program_name());
283 : if (o == NULL) {
284 : log_log(LOG_WARN, "Unavailable stats file: stats will be dumped on stdout");
285 : o = stdout;
286 : }
287 :
288 : stats_file_final_write(o);
289 :
290 : #ifdef ROOTSIM_MPI
291 : stats_files_receive(o);
292 : #endif
293 :
294 : fflush(o);
295 : if (o != stdout)
296 : fclose(o);
297 : }
298 :
299 0 : void stats_time_start(enum stats_time this_stat)
300 : {
301 : last_ts[this_stat] = timer_new();
302 : }
303 :
304 0 : void stats_time_take(enum stats_time this_stat)
305 : {
306 : struct stats_measure *s_mes = &stats_cur.s[this_stat];
307 : const uint64_t t = timer_value(last_ts[this_stat]);
308 :
309 : if (likely(s_mes->count)) {
310 : const int64_t num = (t * s_mes->count - s_mes->sum_t);
311 : s_mes->var_t += ((num * num) << (2 * STD_DEV_POWER_2_EXP)) /
312 : (s_mes->count * (s_mes->count + 1));
313 : }
314 :
315 : s_mes->sum_t += t;
316 : s_mes->count++;
317 : }
318 :
319 0 : void stats_on_gvt(simtime_t gvt)
320 : {
321 : stats_cur.rt = timer_value(sim_start_ts);
322 :
323 : file_write_chunk(stats_tmps[rid], &stats_cur, sizeof(stats_cur));
324 : memset(&stats_cur, 0, sizeof(stats_cur));
325 :
326 : if (rid != 0)
327 : return;
328 :
329 : struct stats_node stats_node_cur =
330 : {.gvt = gvt, .rss = mem_stat_rss_current_get()};
331 : file_write_chunk(stats_node_tmp, &stats_node_cur, sizeof(stats_node_cur));
332 : memset(&stats_node_cur, 0, sizeof(stats_node_cur));
333 :
334 : printf("\rVirtual time: %lf", gvt);
335 : fflush(stdout);
336 : }
337 :
338 0 : void stats_dump(void)
339 : {
340 : puts("");
341 : fflush(stdout);
342 : }
|
