Commit | Line | Data |
---|---|---|
263e529f JA |
1 | /* |
2 | * Status and ETA code | |
3 | */ | |
4 | #include <unistd.h> | |
5 | #include <fcntl.h> | |
6 | #include <string.h> | |
7 | ||
8 | #include "fio.h" | |
263e529f | 9 | |
fca70358 | 10 | static char run_str[REAL_MAX_JOBS + 1]; |
263e529f JA |
11 | |
12 | /* | |
13 | * Sets the status of the 'td' in the printed status map. | |
14 | */ | |
15 | static void check_str_update(struct thread_data *td) | |
16 | { | |
17 | char c = run_str[td->thread_number - 1]; | |
18 | ||
19 | switch (td->runstate) { | |
5ec10eaa | 20 | case TD_REAPED: |
4f7e57a4 JA |
21 | if (td->error) |
22 | c = 'X'; | |
a5e371a6 JA |
23 | else if (td->sig) |
24 | c = 'K'; | |
4f7e57a4 JA |
25 | else |
26 | c = '_'; | |
5ec10eaa JA |
27 | break; |
28 | case TD_EXITED: | |
29 | c = 'E'; | |
30 | break; | |
b29ee5b3 JA |
31 | case TD_RAMP: |
32 | c = '/'; | |
33 | break; | |
5ec10eaa JA |
34 | case TD_RUNNING: |
35 | if (td_rw(td)) { | |
e3b3f81e JA |
36 | if (td_random(td)) { |
37 | if (td->o.rwmix[DDIR_READ] == 100) | |
38 | c = 'r'; | |
39 | else if (td->o.rwmix[DDIR_WRITE] == 100) | |
40 | c = 'w'; | |
41 | else | |
42 | c = 'm'; | |
43 | } else { | |
44 | if (td->o.rwmix[DDIR_READ] == 100) | |
45 | c = 'R'; | |
46 | else if (td->o.rwmix[DDIR_WRITE] == 100) | |
47 | c = 'W'; | |
48 | else | |
49 | c = 'M'; | |
50 | } | |
5ec10eaa JA |
51 | } else if (td_read(td)) { |
52 | if (td_random(td)) | |
53 | c = 'r'; | |
54 | else | |
55 | c = 'R'; | |
56 | } else { | |
57 | if (td_random(td)) | |
58 | c = 'w'; | |
59 | else | |
60 | c = 'W'; | |
61 | } | |
62 | break; | |
b0f65863 JA |
63 | case TD_PRE_READING: |
64 | c = 'p'; | |
65 | break; | |
5ec10eaa JA |
66 | case TD_VERIFYING: |
67 | c = 'V'; | |
68 | break; | |
69 | case TD_FSYNCING: | |
70 | c = 'F'; | |
71 | break; | |
72 | case TD_CREATED: | |
73 | c = 'C'; | |
74 | break; | |
75 | case TD_INITIALIZED: | |
76 | c = 'I'; | |
77 | break; | |
78 | case TD_NOT_CREATED: | |
79 | c = 'P'; | |
80 | break; | |
81 | default: | |
82 | log_err("state %d\n", td->runstate); | |
263e529f JA |
83 | } |
84 | ||
85 | run_str[td->thread_number - 1] = c; | |
86 | } | |
87 | ||
88 | /* | |
89 | * Convert seconds to a printable string. | |
90 | */ | |
9c02f6ef | 91 | static void eta_to_str(char *str, unsigned long eta_sec) |
263e529f JA |
92 | { |
93 | unsigned int d, h, m, s; | |
165faf16 | 94 | int disp_hour = 0; |
263e529f | 95 | |
263e529f JA |
96 | s = eta_sec % 60; |
97 | eta_sec /= 60; | |
98 | m = eta_sec % 60; | |
99 | eta_sec /= 60; | |
100 | h = eta_sec % 24; | |
101 | eta_sec /= 24; | |
102 | d = eta_sec; | |
103 | ||
165faf16 JA |
104 | if (d) { |
105 | disp_hour = 1; | |
1e97cce9 | 106 | str += sprintf(str, "%02ud:", d); |
263e529f | 107 | } |
165faf16 JA |
108 | |
109 | if (h || disp_hour) | |
1e97cce9 | 110 | str += sprintf(str, "%02uh:", h); |
263e529f | 111 | |
1e97cce9 JA |
112 | str += sprintf(str, "%02um:", m); |
113 | str += sprintf(str, "%02us", s); | |
263e529f JA |
114 | } |
115 | ||
116 | /* | |
117 | * Best effort calculation of the estimated pending runtime of a job. | |
118 | */ | |
b29ee5b3 | 119 | static int thread_eta(struct thread_data *td) |
263e529f JA |
120 | { |
121 | unsigned long long bytes_total, bytes_done; | |
1e97cce9 | 122 | unsigned long eta_sec = 0; |
b29ee5b3 JA |
123 | unsigned long elapsed; |
124 | ||
125 | elapsed = (mtime_since_now(&td->epoch) + 999) / 1000; | |
263e529f JA |
126 | |
127 | bytes_total = td->total_io_size; | |
128 | ||
2e3bd4c2 JA |
129 | if (td->o.fill_device && td->o.size == -1ULL) { |
130 | if (!td->fill_device_size || td->fill_device_size == -1ULL) | |
131 | return 0; | |
132 | ||
133 | bytes_total = td->fill_device_size; | |
134 | } | |
135 | ||
74939e38 JA |
136 | /* |
137 | * if writing, bytes_total will be twice the size. If mixing, | |
138 | * assume a 50/50 split and thus bytes_total will be 50% larger. | |
139 | */ | |
0dd8377f | 140 | if (td->o.do_verify && td->o.verify && td_write(td)) { |
74939e38 JA |
141 | if (td_rw(td)) |
142 | bytes_total = bytes_total * 3 / 2; | |
143 | else | |
144 | bytes_total <<= 1; | |
145 | } | |
146 | ||
2dc1bbeb JA |
147 | if (td->o.zone_size && td->o.zone_skip) |
148 | bytes_total /= (td->o.zone_skip / td->o.zone_size); | |
263e529f JA |
149 | |
150 | if (td->runstate == TD_RUNNING || td->runstate == TD_VERIFYING) { | |
cf4464ca | 151 | double perc, perc_t; |
263e529f JA |
152 | |
153 | bytes_done = td->io_bytes[DDIR_READ] + td->io_bytes[DDIR_WRITE]; | |
154 | perc = (double) bytes_done / (double) bytes_total; | |
155 | if (perc > 1.0) | |
156 | perc = 1.0; | |
157 | ||
cf4464ca JA |
158 | if (td->o.time_based) { |
159 | perc_t = (double) elapsed / (double) td->o.timeout; | |
160 | if (perc_t < perc) | |
161 | perc = perc_t; | |
162 | } | |
163 | ||
1e97cce9 | 164 | eta_sec = (unsigned long) (elapsed * (1.0 / perc)) - elapsed; |
263e529f | 165 | |
d3eeeabc JA |
166 | if (td->o.timeout && |
167 | eta_sec > (td->o.timeout + done_secs - elapsed)) | |
168 | eta_sec = td->o.timeout + done_secs - elapsed; | |
263e529f | 169 | } else if (td->runstate == TD_NOT_CREATED || td->runstate == TD_CREATED |
b29ee5b3 | 170 | || td->runstate == TD_INITIALIZED |
b0f65863 JA |
171 | || td->runstate == TD_RAMP |
172 | || td->runstate == TD_PRE_READING) { | |
263e529f JA |
173 | int t_eta = 0, r_eta = 0; |
174 | ||
175 | /* | |
176 | * We can only guess - assume it'll run the full timeout | |
177 | * if given, otherwise assume it'll run at the specified rate. | |
178 | */ | |
b29ee5b3 | 179 | if (td->o.timeout) { |
cda99fa0 SSP |
180 | t_eta = td->o.timeout + td->o.start_delay + |
181 | td->o.ramp_time; | |
b29ee5b3 JA |
182 | |
183 | if (in_ramp_time(td)) { | |
184 | unsigned long ramp_left; | |
185 | ||
cda99fa0 | 186 | ramp_left = mtime_since_now(&td->epoch); |
b29ee5b3 JA |
187 | ramp_left = (ramp_left + 999) / 1000; |
188 | if (ramp_left <= t_eta) | |
189 | t_eta -= ramp_left; | |
190 | } | |
191 | } | |
581e7141 | 192 | if (td->o.rate[0] || td->o.rate[1]) { |
0b9d69ec JA |
193 | r_eta = (bytes_total / 1024) / |
194 | (td->o.rate[0] + td->o.rate[1]); | |
d3eeeabc | 195 | r_eta += td->o.start_delay; |
263e529f JA |
196 | } |
197 | ||
198 | if (r_eta && t_eta) | |
199 | eta_sec = min(r_eta, t_eta); | |
200 | else if (r_eta) | |
201 | eta_sec = r_eta; | |
202 | else if (t_eta) | |
203 | eta_sec = t_eta; | |
204 | else | |
205 | eta_sec = 0; | |
206 | } else { | |
207 | /* | |
208 | * thread is already done or waiting for fsync | |
209 | */ | |
210 | eta_sec = 0; | |
211 | } | |
212 | ||
213 | return eta_sec; | |
214 | } | |
215 | ||
46fda8d0 JA |
216 | static void calc_rate(unsigned long mtime, unsigned long long *io_bytes, |
217 | unsigned long long *prev_io_bytes, unsigned int *rate) | |
218 | { | |
b7f05eb0 JA |
219 | int i; |
220 | ||
221 | for (i = 0; i <= DDIR_WRITE; i++) { | |
222 | unsigned long long diff; | |
223 | ||
224 | diff = io_bytes[i] - prev_io_bytes[i]; | |
225 | rate[i] = ((1000 * diff) / mtime) / 1024; | |
226 | } | |
46fda8d0 JA |
227 | prev_io_bytes[0] = io_bytes[0]; |
228 | prev_io_bytes[1] = io_bytes[1]; | |
229 | } | |
5ec10eaa | 230 | |
adb02ba8 JA |
231 | static void calc_iops(unsigned long mtime, unsigned long long *io_iops, |
232 | unsigned long long *prev_io_iops, unsigned int *iops) | |
233 | { | |
234 | iops[0] = ((io_iops[0] - prev_io_iops[0]) * 1000) / mtime; | |
235 | iops[1] = ((io_iops[1] - prev_io_iops[1]) * 1000) / mtime; | |
236 | prev_io_iops[0] = io_iops[0]; | |
237 | prev_io_iops[1] = io_iops[1]; | |
238 | } | |
239 | ||
263e529f JA |
240 | /* |
241 | * Print status of the jobs we know about. This includes rate estimates, | |
242 | * ETA, thread state, etc. | |
243 | */ | |
af9c9fb3 | 244 | int calc_thread_status(struct jobs_eta *je, int force) |
263e529f | 245 | { |
34572e28 | 246 | struct thread_data *td; |
b75a394f JA |
247 | int i; |
248 | unsigned long rate_time, disp_time, bw_avg_time, *eta_secs; | |
249 | unsigned long long io_bytes[2]; | |
250 | unsigned long long io_iops[2]; | |
46fda8d0 JA |
251 | struct timeval now; |
252 | ||
253 | static unsigned long long rate_io_bytes[2]; | |
254 | static unsigned long long disp_io_bytes[2]; | |
adb02ba8 | 255 | static unsigned long long disp_io_iops[2]; |
46fda8d0 | 256 | static struct timeval rate_prev_time, disp_prev_time; |
6043c579 | 257 | |
af9c9fb3 JA |
258 | if (!force) { |
259 | if (temp_stall_ts || terse_output || eta_print == FIO_ETA_NEVER) | |
260 | return 0; | |
e592a06b | 261 | |
af9c9fb3 JA |
262 | if (!isatty(STDOUT_FILENO) && (eta_print != FIO_ETA_ALWAYS)) |
263 | return 0; | |
264 | } | |
263e529f | 265 | |
46fda8d0 JA |
266 | if (!rate_io_bytes[0] && !rate_io_bytes[1]) |
267 | fill_start_time(&rate_prev_time); | |
268 | if (!disp_io_bytes[0] && !disp_io_bytes[1]) | |
269 | fill_start_time(&disp_prev_time); | |
6043c579 | 270 | |
d3eeeabc JA |
271 | eta_secs = malloc(thread_number * sizeof(unsigned long)); |
272 | memset(eta_secs, 0, thread_number * sizeof(unsigned long)); | |
263e529f | 273 | |
b75a394f JA |
274 | je->elapsed_sec = (mtime_since_genesis() + 999) / 1000; |
275 | ||
6043c579 | 276 | io_bytes[0] = io_bytes[1] = 0; |
adb02ba8 | 277 | io_iops[0] = io_iops[1] = 0; |
bb3884d8 | 278 | bw_avg_time = ULONG_MAX; |
34572e28 | 279 | for_each_td(td, i) { |
b7f05eb0 JA |
280 | if (is_power_of_2(td->o.kb_base)) |
281 | je->is_pow2 = 1; | |
2dc1bbeb JA |
282 | if (td->o.bw_avg_time < bw_avg_time) |
283 | bw_avg_time = td->o.bw_avg_time; | |
46fda8d0 | 284 | if (td->runstate == TD_RUNNING || td->runstate == TD_VERIFYING |
b0f65863 JA |
285 | || td->runstate == TD_FSYNCING |
286 | || td->runstate == TD_PRE_READING) { | |
b75a394f JA |
287 | je->nr_running++; |
288 | je->t_rate += td->o.rate[0] + td->o.rate[1]; | |
289 | je->m_rate += td->o.ratemin[0] + td->o.ratemin[1]; | |
290 | je->t_iops += td->o.rate_iops[0] + td->o.rate_iops[1]; | |
291 | je->m_iops += td->o.rate_iops_min[0] + | |
0b9d69ec | 292 | td->o.rate_iops_min[1]; |
b75a394f | 293 | je->files_open += td->nr_open_files; |
b29ee5b3 | 294 | } else if (td->runstate == TD_RAMP) { |
b75a394f JA |
295 | je->nr_running++; |
296 | je->nr_ramp++; | |
263e529f | 297 | } else if (td->runstate < TD_RUNNING) |
b75a394f | 298 | je->nr_pending++; |
263e529f | 299 | |
b75a394f | 300 | if (je->elapsed_sec >= 3) |
b29ee5b3 | 301 | eta_secs[i] = thread_eta(td); |
263e529f JA |
302 | else |
303 | eta_secs[i] = INT_MAX; | |
304 | ||
305 | check_str_update(td); | |
b29ee5b3 JA |
306 | |
307 | if (td->runstate > TD_RAMP) { | |
308 | io_bytes[0] += td->io_bytes[0]; | |
309 | io_bytes[1] += td->io_bytes[1]; | |
adb02ba8 JA |
310 | io_iops[0] += td->io_blocks[0]; |
311 | io_iops[1] += td->io_blocks[1]; | |
b29ee5b3 | 312 | } |
263e529f JA |
313 | } |
314 | ||
315 | if (exitall_on_terminate) | |
b75a394f | 316 | je->eta_sec = INT_MAX; |
263e529f | 317 | else |
b75a394f | 318 | je->eta_sec = 0; |
263e529f | 319 | |
34572e28 | 320 | for_each_td(td, i) { |
9c5a3854 | 321 | if (exitall_on_terminate) { |
b75a394f JA |
322 | if (eta_secs[i] < je->eta_sec) |
323 | je->eta_sec = eta_secs[i]; | |
9c5a3854 | 324 | } else { |
b75a394f JA |
325 | if (eta_secs[i] > je->eta_sec) |
326 | je->eta_sec = eta_secs[i]; | |
9c5a3854 | 327 | } |
263e529f JA |
328 | } |
329 | ||
eecf272f JA |
330 | free(eta_secs); |
331 | ||
46fda8d0 JA |
332 | fio_gettime(&now, NULL); |
333 | rate_time = mtime_since(&rate_prev_time, &now); | |
334 | ||
b29ee5b3 | 335 | if (write_bw_log && rate_time > bw_avg_time && !in_ramp_time(td)) { |
b75a394f | 336 | calc_rate(rate_time, io_bytes, rate_io_bytes, je->rate); |
46fda8d0 | 337 | memcpy(&rate_prev_time, &now, sizeof(now)); |
b75a394f JA |
338 | add_agg_sample(je->rate[DDIR_READ], DDIR_READ, 0); |
339 | add_agg_sample(je->rate[DDIR_WRITE], DDIR_WRITE, 0); | |
6043c579 JA |
340 | } |
341 | ||
46fda8d0 | 342 | disp_time = mtime_since(&disp_prev_time, &now); |
a5b01f1b JA |
343 | |
344 | /* | |
345 | * Allow a little slack, the target is to print it every 1000 msecs | |
346 | */ | |
af9c9fb3 | 347 | if (!force && disp_time < 900) |
b75a394f | 348 | return 0; |
46fda8d0 | 349 | |
b75a394f JA |
350 | calc_rate(disp_time, io_bytes, disp_io_bytes, je->rate); |
351 | calc_iops(disp_time, io_iops, disp_io_iops, je->iops); | |
adb02ba8 | 352 | |
46fda8d0 JA |
353 | memcpy(&disp_prev_time, &now, sizeof(now)); |
354 | ||
af9c9fb3 | 355 | if (!force && !je->nr_running && !je->nr_pending) |
b75a394f JA |
356 | return 0; |
357 | ||
1d1f45ae JA |
358 | je->nr_threads = thread_number; |
359 | memcpy(je->run_str, run_str, thread_number * sizeof(char)); | |
360 | ||
b75a394f JA |
361 | return 1; |
362 | } | |
363 | ||
cf451d1e | 364 | void display_thread_status(struct jobs_eta *je) |
b75a394f | 365 | { |
b75a394f JA |
366 | static int linelen_last; |
367 | static int eta_good; | |
79074e7c | 368 | char output[REAL_MAX_JOBS + 512], *p = output; |
b75a394f JA |
369 | char eta_str[128]; |
370 | double perc = 0.0; | |
b75a394f | 371 | |
cf451d1e JA |
372 | if (je->eta_sec != INT_MAX && je->elapsed_sec) { |
373 | perc = (double) je->elapsed_sec / (double) (je->elapsed_sec + je->eta_sec); | |
374 | eta_to_str(eta_str, je->eta_sec); | |
b75a394f JA |
375 | } |
376 | ||
cf451d1e JA |
377 | p += sprintf(p, "Jobs: %d (f=%d)", je->nr_running, je->files_open); |
378 | if (je->m_rate || je->t_rate) { | |
581e7141 JA |
379 | char *tr, *mr; |
380 | ||
b7f05eb0 JA |
381 | mr = num2str(je->m_rate, 4, 0, je->is_pow2); |
382 | tr = num2str(je->t_rate, 4, 0, je->is_pow2); | |
37db14fe | 383 | p += sprintf(p, ", CR=%s/%s KB/s", tr, mr); |
581e7141 JA |
384 | free(tr); |
385 | free(mr); | |
cf451d1e JA |
386 | } else if (je->m_iops || je->t_iops) |
387 | p += sprintf(p, ", CR=%d/%d IOPS", je->t_iops, je->m_iops); | |
388 | if (je->eta_sec != INT_MAX && je->nr_running) { | |
0721d11e | 389 | char perc_str[32]; |
adb02ba8 | 390 | char *iops_str[2]; |
d1bd7213 | 391 | char *rate_str[2]; |
79074e7c | 392 | size_t left; |
adb02ba8 | 393 | int l; |
5ec10eaa | 394 | |
cf451d1e | 395 | if ((!je->eta_sec && !eta_good) || je->nr_ramp == je->nr_running) |
cac58fd5 JA |
396 | strcpy(perc_str, "-.-% done"); |
397 | else { | |
398 | eta_good = 1; | |
399 | perc *= 100.0; | |
0721d11e | 400 | sprintf(perc_str, "%3.1f%% done", perc); |
cac58fd5 | 401 | } |
0721d11e | 402 | |
b7f05eb0 JA |
403 | rate_str[0] = num2str(je->rate[0], 5, 1024, je->is_pow2); |
404 | rate_str[1] = num2str(je->rate[1], 5, 1024, je->is_pow2); | |
d1bd7213 | 405 | |
cf451d1e JA |
406 | iops_str[0] = num2str(je->iops[0], 4, 1, 0); |
407 | iops_str[1] = num2str(je->iops[1], 4, 1, 0); | |
adb02ba8 | 408 | |
79074e7c JA |
409 | left = sizeof(output) - (p - output) - 1; |
410 | ||
411 | l = snprintf(p, left, ": [%s] [%s] [%s/%s /s] [%s/%s iops] [eta %s]", | |
1d1f45ae JA |
412 | je->run_str, perc_str, rate_str[0], |
413 | rate_str[1], iops_str[0], iops_str[1], eta_str); | |
37db14fe | 414 | p += l; |
adb02ba8 | 415 | if (l >= 0 && l < linelen_last) |
37db14fe | 416 | p += sprintf(p, "%*s", linelen_last - l, ""); |
adb02ba8 | 417 | linelen_last = l; |
d1bd7213 JA |
418 | |
419 | free(rate_str[0]); | |
420 | free(rate_str[1]); | |
adb02ba8 JA |
421 | free(iops_str[0]); |
422 | free(iops_str[1]); | |
263e529f | 423 | } |
37db14fe JA |
424 | p += sprintf(p, "\r"); |
425 | ||
cf451d1e JA |
426 | printf("%s", output); |
427 | fflush(stdout); | |
263e529f JA |
428 | } |
429 | ||
cf451d1e JA |
430 | void print_thread_status(void) |
431 | { | |
1d1f45ae | 432 | struct jobs_eta *je; |
b814fb26 | 433 | size_t size; |
1d1f45ae | 434 | |
b814fb26 JA |
435 | if (!thread_number) |
436 | return; | |
cf451d1e | 437 | |
b814fb26 JA |
438 | size = sizeof(*je) + thread_number * sizeof(char) + 1; |
439 | je = malloc(size); | |
440 | memset(je, 0, size); | |
cf451d1e | 441 | |
af9c9fb3 | 442 | if (calc_thread_status(je, 0)) |
1d1f45ae | 443 | display_thread_status(je); |
cf451d1e | 444 | |
1d1f45ae | 445 | free(je); |
cf451d1e | 446 | } |
b75a394f | 447 | |
2b13e716 | 448 | void print_status_init(int thr_number) |
263e529f | 449 | { |
2b13e716 | 450 | run_str[thr_number] = 'P'; |
263e529f | 451 | } |