Thrill  0.1
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
iostats.cpp
Go to the documentation of this file.
1 /***************************************************************************
2  * foxxll/io/iostats.cpp
3  *
4  * Part of FOXXLL. See http://foxxll.org
5  *
6  * Copyright (C) 2002-2004 Roman Dementiev <[email protected]>
7  * Copyright (C) 2008-2010 Andreas Beckmann <[email protected]>
8  * Copyright (C) 2009, 2010 Johannes Singler <[email protected]>
9  * Copyright (C) 2016 Alex Schickedanz <[email protected]>
10  *
11  * Distributed under the Boost Software License, Version 1.0.
12  * (See accompanying file LICENSE_1_0.txt or copy at
13  * http://www.boost.org/LICENSE_1_0.txt)
14  **************************************************************************/
15 
16 #include <array>
17 #include <iomanip>
18 #include <mutex>
19 #include <numeric>
20 #include <sstream>
21 #include <string>
22 
23 #include <tlx/logger.hpp>
24 
25 #include <foxxll/common/timer.hpp>
26 #include <foxxll/common/types.hpp>
27 #include <foxxll/io/iostats.hpp>
29 
30 namespace foxxll {
31 
32 /******************************************************************************/
33 // file_stats
34 
35 file_stats::file_stats(unsigned int device_id)
36  : device_id_(device_id),
37  read_count_(0), write_count_(0),
38  read_bytes_(0), write_bytes_(0),
39  read_time_(0.0), write_time_(0.0),
40  p_begin_read_(0.0), p_begin_write_(0.0),
41  acc_reads_(0), acc_writes_(0)
42 { }
43 
44 void file_stats::write_started(const size_t size, double now)
45 {
46  if (now == 0.0)
47  now = timestamp();
48 
49  {
50  std::unique_lock<std::mutex> write_lock(write_mutex_);
51 
52  ++write_count_;
53  write_bytes_ += size;
54  const double diff = now - p_begin_write_;
55  write_time_ += (acc_writes_++) * diff;
56  p_begin_write_ = now;
57  }
58 
60 }
61 
62 void file_stats::write_canceled(const size_t size)
63 {
64  {
65  std::unique_lock<std::mutex> write_lock(write_mutex_);
66 
67  --write_count_;
68  write_bytes_ -= size;
69  }
71 }
72 
74 {
75  double now = timestamp();
76 
77  {
78  std::unique_lock<std::mutex> write_lock(write_mutex_);
79 
80  const double diff = now - p_begin_write_;
81  write_time_ += (acc_writes_--) * diff;
82  p_begin_write_ = now;
83  }
84 
86 }
87 
88 void file_stats::write_op_finished(const size_t size, double duration)
89 {
90  std::unique_lock<std::mutex> write_lock(write_mutex_);
91 
92  ++write_count_;
93  write_time_ += duration;
94  write_bytes_ += size;
95 }
96 
97 void file_stats::read_started(const size_t size, double now)
98 {
99  if (now == 0.0)
100  now = timestamp();
101 
102  {
103  std::unique_lock<std::mutex> read_lock(read_mutex_);
104 
105  ++read_count_;
106  read_bytes_ += size;
107  const double diff = now - p_begin_read_;
108  read_time_ += (acc_reads_++) * diff;
109  p_begin_read_ = now;
110  }
111 
113 }
114 
115 void file_stats::read_canceled(const size_t size)
116 {
117  {
118  std::unique_lock<std::mutex> read_lock(read_mutex_);
119 
120  --read_count_;
121  read_bytes_ -= size;
122  }
123  read_finished();
124 }
125 
127 {
128  double now = timestamp();
129 
130  {
131  std::unique_lock<std::mutex> read_lock(read_mutex_);
132 
133  const double diff = now - p_begin_read_;
134  read_time_ += (acc_reads_--) * diff;
135  p_begin_read_ = now;
136  }
137 
139 }
140 
141 void file_stats::read_op_finished(const size_t size, double duration)
142 {
143  std::unique_lock<std::mutex> write_lock(read_mutex_);
144 
145  ++read_count_;
146  read_time_ += duration;
147  read_bytes_ += size;
148 }
149 
150 /******************************************************************************/
151 // file_stats_data
152 
154 {
156  device_id_ != a.device_id_, std::runtime_error,
157  "foxxll::file_stats_data objects do not belong to the same file/disk"
158  );
159 
160  file_stats_data fsd;
161  fsd.device_id_ = device_id_;
162 
167  fsd.read_time_ = read_time_ + a.read_time_;
169 
170  return fsd;
171 }
172 
174 {
176  device_id_ != a.device_id_, std::runtime_error,
177  "foxxll::file_stats_data objects do not belong to the same file/disk"
178  );
179 
180  file_stats_data fsd;
181  fsd.device_id_ = device_id_;
182 
187  fsd.read_time_ = read_time_ - a.read_time_;
189 
190  return fsd;
191 }
192 
193 /******************************************************************************/
194 // stats
195 
197  : creation_time_(timestamp()),
198  p_reads_(0.0), p_writes_(0.0),
199  p_begin_read_(0.0), p_begin_write_(0.0),
200  p_ios_(0.0),
201  p_begin_io_(0.0),
202 
203  acc_reads_(0.0), acc_writes_(0.0),
204  acc_ios_(0.0),
205 
206  t_waits_(0.0), p_waits_(0.0),
207  p_begin_wait_(0.0),
208  t_wait_read_(0.0), p_wait_read_(0.0),
209  p_begin_wait_read_(0.0),
210  t_wait_write_(0.0), p_wait_write_(0.0),
211  p_begin_wait_write_(0.0),
212  acc_waits_(0.0),
213  acc_wait_read_(0.0), acc_wait_write_(0.0)
214 { }
215 
216 #ifndef FOXXLL_DO_NOT_COUNT_WAIT_TIME
218 {
219  const double now = timestamp();
220  {
221  std::unique_lock<std::mutex> wait_lock(wait_mutex_);
222 
223  double diff = now - p_begin_wait_;
224  t_waits_ += acc_waits_ * diff;
225  p_begin_wait_ = now;
226  p_waits_ += (acc_waits_++) ? diff : 0.0;
227 
228  if (wait_op == WAIT_OP_READ) {
229  diff = now - p_begin_wait_read_;
230  t_wait_read_ += acc_wait_read_ * diff;
231  p_begin_wait_read_ = now;
232  p_wait_read_ += (acc_wait_read_++) ? diff : 0.0;
233  }
234  else /* if (wait_op == WAIT_OP_WRITE) */ {
235  // wait_any() is only used from write_pool and buffered_writer, so account WAIT_OP_ANY for WAIT_OP_WRITE, too
236  diff = now - p_begin_wait_write_;
237  t_wait_write_ += acc_wait_write_ * diff;
238  p_begin_wait_write_ = now;
239  p_wait_write_ += (acc_wait_write_++) ? diff : 0.0;
240  }
241  }
242 }
243 
245 {
246  const double now = timestamp();
247  {
248  std::unique_lock<std::mutex> wait_lock(wait_mutex_);
249 
250  double diff = now - p_begin_wait_;
251  t_waits_ += acc_waits_ * diff;
252  p_begin_wait_ = now;
253  p_waits_ += (acc_waits_--) ? diff : 0.0;
254 
255  if (wait_op == WAIT_OP_READ) {
256  double diff2 = now - p_begin_wait_read_;
257  t_wait_read_ += acc_wait_read_ * diff2;
258  p_begin_wait_read_ = now;
259  p_wait_read_ += (acc_wait_read_--) ? diff2 : 0.0;
260  }
261  else /* if (wait_op == WAIT_OP_WRITE) */ {
262  double diff2 = now - p_begin_wait_write_;
263  t_wait_write_ += acc_wait_write_ * diff2;
264  p_begin_wait_write_ = now;
265  p_wait_write_ += (acc_wait_write_--) ? diff2 : 0.0;
266  }
267 #ifdef FOXXLL_WAIT_LOG_ENABLED
268  if (waitlog)
269  LOG1 << (now - last_reset) << "\t"
270  << ((wait_op == WAIT_OP_READ) ? diff : 0.0) << "\t"
271  << ((wait_op != WAIT_OP_READ) ? diff : 0.0) << "\t"
272  << t_wait_read_ << "\t" << t_wait_write_ << "\n" << line_prefix << std::flush;
273 #endif
274  }
275 }
276 #endif
277 
278 void stats::p_write_started(const double now)
279 {
280  {
281  std::unique_lock<std::mutex> write_lock(write_mutex_);
282 
283  const double diff = now - p_begin_write_;
284  p_begin_write_ = now;
285  p_writes_ += (acc_writes_++) ? diff : 0.0;
286  }
287  {
288  std::unique_lock<std::mutex> io_lock(io_mutex_);
289 
290  const double diff = now - p_begin_io_;
291  p_ios_ += (acc_ios_++) ? diff : 0.0;
292  p_begin_io_ = now;
293  }
294 }
295 
296 void stats::p_write_finished(const double now)
297 {
298  {
299  std::unique_lock<std::mutex> write_lock(write_mutex_);
300 
301  const double diff = now - p_begin_write_;
302  p_begin_write_ = now;
303  p_writes_ += (acc_writes_--) ? diff : 0.0;
304  }
305  {
306  std::unique_lock<std::mutex> io_lock(io_mutex_);
307 
308  const double diff = now - p_begin_io_;
309  p_ios_ += (acc_ios_--) ? diff : 0.0;
310  p_begin_io_ = now;
311  }
312 }
313 
314 void stats::p_read_started(const double now)
315 {
316  {
317  std::unique_lock<std::mutex> read_lock(read_mutex_);
318 
319  const double diff = now - p_begin_read_;
320  p_begin_read_ = now;
321  p_reads_ += (acc_reads_++) ? diff : 0.0;
322  }
323  {
324  std::unique_lock<std::mutex> io_lock(io_mutex_);
325 
326  const double diff = now - p_begin_io_;
327  p_ios_ += (acc_ios_++) ? diff : 0.0;
328  p_begin_io_ = now;
329  }
330 }
331 
332 void stats::p_read_finished(const double now)
333 {
334  {
335  std::unique_lock<std::mutex> read_lock(read_mutex_);
336 
337  const double diff = now - p_begin_read_;
338  p_begin_read_ = now;
339  p_reads_ += (acc_reads_--) ? diff : 0.0;
340  }
341  {
342  std::unique_lock<std::mutex> io_lock(io_mutex_);
343 
344  const double diff = now - p_begin_io_;
345  p_ios_ += (acc_ios_--) ? diff : 0.0;
346  p_begin_io_ = now;
347  }
348 }
349 
350 file_stats* stats::create_file_stats(unsigned int device_id)
351 {
352  std::unique_lock<std::mutex> lock(list_mutex_);
353  auto it = std::lower_bound(
354  file_stats_list_.begin(), file_stats_list_.end(),
355  device_id, [](const file_stats& fs, unsigned id) {
356  return fs.get_device_id() < id;
357  }
358  );
359  if (it != file_stats_list_.end() && it->get_device_id())
360  return &*it;
361 
362  file_stats_list_.emplace(it, /* construction: */ device_id);
363  return &file_stats_list_.back();
364 }
365 
366 std::vector<file_stats_data> stats::deepcopy_file_stats_data_list() const
367 {
368  std::unique_lock<std::mutex> lock(list_mutex_);
369  return {
370  file_stats_list_.cbegin(), file_stats_list_.cend()
371  };
372 }
373 
374 std::ostream& operator << (std::ostream& o, const stats& s)
375 {
376  o << stats_data(s);
377  return o;
378 }
379 
380 /******************************************************************************/
381 // stats_data
382 
383 template <typename T, typename Functor>
384 T stats_data::fetch_sum(const Functor& get_value) const
385 {
386  return std::accumulate(
387  file_stats_data_list_.cbegin(), file_stats_data_list_.cend(), T(0),
388  [get_value](T sum, const auto& x) { return sum + get_value(x); });
389 }
390 
391 template <typename T>
392 template <typename Functor>
394  const std::vector<file_stats_data>& fs, const Functor& get_value)
395 {
396  values_per_device.reserve(fs.size());
397  for (const auto& f : fs) {
398  values_per_device.emplace_back(get_value(f), f.get_device_id());
399  }
400 
401  std::sort(
402  values_per_device.begin(), values_per_device.end(),
403  [](std::pair<T, unsigned> a, std::pair<T, unsigned> b) {
404  return a.first < b.first;
405  }
406  );
407 
408  if (values_per_device.size() != 0)
409  {
410  min = values_per_device.front().first;
411  max = values_per_device.back().first;
412 
413  const size_t mid = values_per_device.size() / 2;
414  median =
415  (values_per_device.size() % 2)
416  ? values_per_device[mid].first
417  : (values_per_device[mid - 1].first + values_per_device[mid].first) / 2.0;
418 
419  total = std::accumulate(
420  values_per_device.cbegin(), values_per_device.cend(), T(0),
421  [](T sum, const auto& x) { return sum + x.first; });
422 
423  average = static_cast<double>(total) / values_per_device.size();
424  }
425  else
426  {
427  min = std::numeric_limits<T>::quiet_NaN();
428  max = std::numeric_limits<T>::quiet_NaN();
429  median = std::numeric_limits<T>::quiet_NaN();
430  total = std::numeric_limits<T>::quiet_NaN();
431  average = std::numeric_limits<T>::quiet_NaN();
432  }
433 }
434 
435 struct FileStatsDataCompare {
436  long long operator () (const file_stats_data& a, const file_stats_data& b) const
437  {
438  return static_cast<long long>(a.get_device_id())
439  - static_cast<long long>(b.get_device_id());
440  }
441 };
442 
444 {
445  stats_data s;
446 
449  a.file_stats_data_list_.cbegin(), a.file_stats_data_list_.cend(),
450  std::back_inserter(s.file_stats_data_list_),
451  FileStatsDataCompare(),
452  [](const file_stats_data& a, const file_stats_data& b) {
453  return a + b;
454  }
455  );
456 
457  s.p_reads_ = p_reads_ + a.p_reads_;
458  s.p_writes_ = p_writes_ + a.p_writes_;
459  s.p_ios_ = p_ios_ + a.p_ios_;
460  s.t_wait = t_wait + a.t_wait;
461  s.t_wait_read_ = t_wait_read_ + a.t_wait_read_;
462  s.t_wait_write_ = t_wait_write_ + a.t_wait_write_;
463  s.elapsed_ = elapsed_ + a.elapsed_;
464  return s;
465 }
466 
468 {
469  stats_data s;
470 
473  a.file_stats_data_list_.cbegin(), a.file_stats_data_list_.cend(),
474  std::back_inserter(s.file_stats_data_list_),
475  FileStatsDataCompare(),
476  [](const file_stats_data& a, const file_stats_data& b) {
477  return a - b;
478  }
479  );
480 
481  s.p_reads_ = p_reads_ - a.p_reads_;
482  s.p_writes_ = p_writes_ - a.p_writes_;
483  s.p_ios_ = p_ios_ - a.p_ios_;
484  s.t_wait = t_wait - a.t_wait;
485  s.t_wait_read_ = t_wait_read_ - a.t_wait_read_;
486  s.t_wait_write_ = t_wait_write_ - a.t_wait_write_;
487  s.elapsed_ = elapsed_ - a.elapsed_;
488  return s;
489 }
490 
491 size_t stats_data::num_files() const
492 {
493  return file_stats_data_list_.size();
494 }
495 
497 {
498  return fetch_sum<unsigned>(
499  [](const file_stats_data& fsd) { return fsd.get_read_count(); });
500 }
501 
503 {
504  return {
505  file_stats_data_list_, [](const file_stats_data& fsd) {
506  return fsd.get_read_count();
507  }
508  };
509 }
510 
512 {
513  return fetch_sum<unsigned>(
514  [](const file_stats_data& fsd) { return fsd.get_write_count(); });
515 }
516 
518 {
519  return {
520  file_stats_data_list_, [](const file_stats_data& fsd) {
521  return fsd.get_write_count();
522  }
523  };
524 }
525 
527 {
528  return fetch_sum<external_size_type>(
529  [](const file_stats_data& fsd) { return fsd.get_read_bytes(); });
530 }
531 
534 {
535  return {
536  file_stats_data_list_, [](const file_stats_data& fsd) {
537  return fsd.get_read_bytes();
538  }
539  };
540 }
541 
543 {
544  return fetch_sum<external_size_type>(
545  [](const file_stats_data& fsd) { return fsd.get_write_bytes(); });
546 }
547 
550 {
551  return {
552  file_stats_data_list_, [](const file_stats_data& fsd) {
553  return fsd.get_write_bytes();
554  }
555  };
556 }
557 
559 {
560  return fetch_sum<double>(
561  [](const file_stats_data& fsd) { return fsd.get_read_time(); });
562 }
563 
565 {
566  return {
567  file_stats_data_list_, [](const file_stats_data& fsd) {
568  return fsd.get_read_time();
569  }
570  };
571 }
572 
574 {
575  return fetch_sum<double>(
576  [](const file_stats_data& fsd) { return fsd.get_write_time(); });
577 }
578 
580 {
581  return {
582  file_stats_data_list_, [](const file_stats_data& fsd) {
583  return fsd.get_write_time();
584  }
585  };
586 }
587 
589 {
590  return p_reads_;
591 }
592 
594 {
595  return p_writes_;
596 }
597 
599 {
600  return p_ios_;
601 }
602 
604 {
605  return {
606  file_stats_data_list_, [](const file_stats_data& fsd) {
607  return static_cast<double>(fsd.get_read_bytes()) / fsd.get_read_time();
608  }
609  };
610 }
611 
613 {
614  return {
615  file_stats_data_list_, [this](const file_stats_data& fsd) {
616  return static_cast<double>(fsd.get_read_bytes()) / p_reads_;
617  }
618  };
619 }
620 
622 {
623  return {
624  file_stats_data_list_, [](const file_stats_data& fsd) {
625  return static_cast<double>(fsd.get_write_bytes()) / fsd.get_write_time();
626  }
627  };
628 }
629 
631 {
632  return {
633  file_stats_data_list_, [this](const file_stats_data& fsd) {
634  return static_cast<double>(fsd.get_write_bytes()) / p_writes_;
635  }
636  };
637 }
638 
640 {
641  return {
642  file_stats_data_list_, [this](const file_stats_data& fsd) {
643  return static_cast<double>(fsd.get_read_bytes() + fsd.get_write_bytes()) / p_ios_;
644  }
645  };
646 }
647 
649 {
650  return t_wait;
651 }
652 
654 {
655  return t_wait_read_;
656 }
657 
659 {
660  return t_wait_write_;
661 }
662 
663 void stats_data::to_ostream(std::ostream& o, const std::string line_prefix) const
664 {
665  constexpr double one_mib = 1024.0 * 1024;
666 
667  o << "I/O statistics\n" << line_prefix;
668 
669  size_t nf = num_files();
670  if (nf != 1) {
671  o << " number of disks/files : "
672  << nf << "\n" << line_prefix;
673  }
674 
675  const auto read_bytes_summary = get_read_bytes_summary();
676  const auto write_bytes_summary = get_write_bytes_summary();
677 
678  const auto read_speed_summary = get_read_speed_summary();
679  const auto pread_speed_summary = get_pread_speed_summary();
680  const auto write_speed_summary = get_write_speed_summary();
681  const auto pwrite_speed_summary = get_pwrite_speed_summary();
682  const auto pio_speed_summary = get_pio_speed_summary();
683 
684  o << " total number of reads : "
685  << add_IEC_binary_multiplier(get_read_count()) << "\n" << line_prefix;
686  o << " average block size (read) : "
688  << "\n" << line_prefix;
689  o << " number of bytes read from disks : "
690  << add_IEC_binary_multiplier(get_read_bytes(), "B") << "\n" << line_prefix;
691  o << " time spent in serving all read requests : "
692  << get_read_time() << " s"
693  << " @ " << (static_cast<double>(get_read_bytes()) / one_mib / get_read_time()) << " MiB/s";
694  if (nf > 1) {
695  o << " (min: " << read_speed_summary.min / one_mib << " MiB/s, "
696  << "max: " << read_speed_summary.max / one_mib << " MiB/s)";
697  }
698  o << "\n" << line_prefix;
699  o << " time spent in reading (parallel read time) : "
700  << get_pread_time() << " s"
701  << " @ " << (static_cast<double>(get_read_bytes()) / one_mib / get_pread_time()) << " MiB/s"
702  << "\n" << line_prefix;
703  if (nf > 1) {
704  o << " reading speed per file : "
705  << "min: " << pread_speed_summary.min / one_mib << " MiB/s, "
706  << "median: " << pread_speed_summary.median / one_mib << " MiB/s, "
707  << "max: " << pread_speed_summary.max / one_mib << " MiB/s"
708  << "\n" << line_prefix;
709  }
710 
711  o << " total number of writes : "
712  << add_IEC_binary_multiplier(get_write_count()) << "\n" << line_prefix
713  << " average block size (write) : "
714  << add_IEC_binary_multiplier(get_write_count() ? get_write_bytes() / get_write_count() : 0, "B") << "\n" << line_prefix
715  << " number of bytes written to disks : "
716  << add_IEC_binary_multiplier(get_write_bytes(), "B") << "\n" << line_prefix
717  << " time spent in serving all write requests : "
718  << get_write_time() << " s"
719  << " @ " << (static_cast<double>(get_write_bytes()) / one_mib / get_write_time()) << " MiB/s";
720 
721  if (nf > 1) {
722  o << " (min: " << write_speed_summary.min / one_mib << " MiB/s, "
723  << "max: " << write_speed_summary.max / one_mib << " MiB/s)";
724  }
725  o << "\n" << line_prefix;
726 
727  o << " time spent in writing (parallel write time): " << get_pwrite_time() << " s"
728  << " @ " << (static_cast<double>(get_write_bytes()) / one_mib / get_pwrite_time()) << " MiB/s"
729  << "\n" << line_prefix;
730  if (nf > 1) {
731  o << " parallel write speed per file : "
732  << "min: " << pwrite_speed_summary.min / one_mib << " MiB/s, "
733  << "median: " << pwrite_speed_summary.median / one_mib << " MiB/s, "
734  << "max: " << pwrite_speed_summary.max / one_mib << " MiB/s"
735  << "\n" << line_prefix;
736  }
737 
738  o << " time spent in I/O (parallel I/O time) : " << get_pio_time() << " s"
739  << " @ " << (static_cast<double>((get_read_bytes()) + get_write_bytes()) / one_mib / get_pio_time()) << " MiB/s"
740  << "\n" << line_prefix;
741  if (nf > 1) {
742  o << " parallel I/O speed per file : "
743  << "min: " << pio_speed_summary.min / one_mib << " MiB/s, "
744  << "median: " << pio_speed_summary.median / one_mib << " MiB/s, "
745  << "max: " << pio_speed_summary.max / one_mib << " MiB/s"
746  << "\n" << line_prefix;
747  }
748 #ifndef FOXXLL_DO_NOT_COUNT_WAIT_TIME
749  o << " I/O wait time : "
750  << get_io_wait_time() << " s\n" << line_prefix;
751  if (get_wait_read_time() != 0.0)
752  o << " I/O wait4read time : "
753  << get_wait_read_time() << " s\n" << line_prefix;
754  if (get_wait_write_time() != 0.0)
755  o << " I/O wait4write time : "
756  << get_wait_write_time() << " s\n" << line_prefix;
757 #endif
758  o << " Time since the last reset : "
759  << get_elapsed_time() << " s";
760 
761  if (pio_speed_summary.min / pio_speed_summary.max < 0.5 ||
762  pread_speed_summary.min / pread_speed_summary.max < 0.5 ||
763  pwrite_speed_summary.min / pwrite_speed_summary.max < 0.5)
764  {
765  o << "\n" << line_prefix
766  << "WARNING: Slow disk(s) detected.\n" << line_prefix
767  << " Reading: ";
768  o << pread_speed_summary.values_per_device.front().second
769  << "@ " << pread_speed_summary.values_per_device.front().first / one_mib << " MiB/s";
770  for (int i = 1; pread_speed_summary.values_per_device[i].first / pread_speed_summary.values_per_device.back().first < 0.5; ++i)
771  {
772  o << ", " << pread_speed_summary.values_per_device[i].second
773  << "@ " << pread_speed_summary.values_per_device[i].first / one_mib << " MiB/s";
774  }
775  o << "\n" << line_prefix
776  << " Writing: "
777  << pwrite_speed_summary.values_per_device.front().second
778  << "@ " << pwrite_speed_summary.values_per_device.front().first / one_mib << " MiB/s";
779  for (int i = 1; pwrite_speed_summary.values_per_device[i].first / pwrite_speed_summary.values_per_device.back().first < 0.5; ++i)
780  {
781  o << ", " << pwrite_speed_summary.values_per_device[i].second
782  << "@ " << pwrite_speed_summary.values_per_device[i].first / one_mib << " MiB/s";
783  }
784  }
785 
786  if (static_cast<double>(read_bytes_summary.min) / read_bytes_summary.max < 0.5 ||
787  static_cast<double>(write_bytes_summary.min) / write_bytes_summary.max < 0.5)
788  {
789  o << "\n" << line_prefix <<
790  "WARNING: Bad load balancing.\n" << line_prefix
791  << " Smallest read load on disk "
792  << read_bytes_summary.values_per_device.front().second
793  << " @ " << add_IEC_binary_multiplier(read_bytes_summary.values_per_device.front().first, "B")
794  << "\n" << line_prefix
795  << " Biggest read load on disk "
796  << read_bytes_summary.values_per_device.back().second
797  << " @ " << add_IEC_binary_multiplier(read_bytes_summary.values_per_device.back().first, "B")
798  << "\n" << line_prefix
799  << " Smallest write load on disk "
800  << write_bytes_summary.values_per_device.front().second
801  << " @ " << add_IEC_binary_multiplier(write_bytes_summary.values_per_device.front().first, "B")
802  << "\n" << line_prefix
803  << " Biggest write load on disk "
804  << write_bytes_summary.values_per_device.back().second
805  << " @ " << add_IEC_binary_multiplier(write_bytes_summary.values_per_device.back().first, "B")
806  << "\n" << line_prefix;
807  }
808 
809  o << std::endl;
810 }
811 
813 {
814  const auto result = foxxll::stats_data(*foxxll::stats::get_instance()) - begin_;
815 
816  std::ostringstream ss;
817 
818  ss << (message_.empty() ? "" : "Finished ") << message_ << ". ";
819 
820  if (bytes_) {
821  const auto bps = static_cast<double>(bytes_) / result.get_elapsed_time();
822  ss << "Processed " << tlx::format_iec_units(bytes_) << "B"
823  << " @ " << tlx::format_iec_units(static_cast<uint64_t>(bps)) << "B/s. ";
824  }
825 
826  result.to_ostream(ss, key_);
827 
828  LOG1 << ss.str();
829 }
830 
831 } // namespace foxxll
832 
833 /**************************************************************************/
std::mutex io_mutex_
Definition: iostats.hpp:358
std::mutex write_mutex_
Definition: iostats.hpp:358
double get_write_time() const
Definition: iostats.cpp:573
double get_pread_time() const
Definition: iostats.cpp:588
static uint_pair max()
return an uint_pair instance containing the largest value possible
Definition: uint_types.hpp:226
external_size_type write_bytes_
Definition: iostats.hpp:53
file_stats_data operator+(const file_stats_data &a) const
Definition: iostats.cpp:153
int acc_reads_
number of requests, participating in parallel operation
Definition: iostats.hpp:60
std::ostream & operator<<(std::ostream &o, const stats &s)
Definition: iostats.cpp:374
external_size_type write_bytes_
Definition: iostats.hpp:255
double p_begin_wait_write_
Definition: iostats.hpp:354
int acc_wait_read_
Definition: iostats.hpp:356
uint64_t bytes_
bytes processed
Definition: iostats.hpp:671
std::mutex write_mutex_
Definition: iostats.hpp:62
void p_read_finished(double now)
Definition: iostats.cpp:332
double T
unsigned read_count_
number of operations
Definition: iostats.hpp:253
double p_begin_read_
start time of parallel operation
Definition: iostats.hpp:57
void write_started(const size_t size_, double now=0.0)
Definition: iostats.cpp:44
#define LOG1
Definition: logger.hpp:145
std::vector< file_stats_data > deepcopy_file_stats_data_list() const
return list of file's stats data (deeply copied from each file_stats)
Definition: iostats.cpp:366
summary(const std::vector< file_stats_data > &fs, const Functor &get_value)
Definition: iostats.cpp:393
T fetch_sum(const Functor &get_value) const
aggregator
Definition: iostats.cpp:384
double p_begin_write_
Definition: iostats.hpp:57
void report() const
print out relative stats via LOG
Definition: iostats.cpp:812
std::mutex read_mutex_
Definition: iostats.hpp:62
double p_begin_io_
Definition: iostats.hpp:340
std::mutex list_mutex_
Definition: iostats.hpp:330
std::mutex wait_mutex_
Definition: iostats.hpp:358
void read_op_finished(const size_t size_, double duration)
Definition: iostats.cpp:141
OutputIterator merge_combine(InputIterator1 first1, InputIterator1 last1, InputIterator2 first2, InputIterator2 last2, OutputIterator result, Comparator cmp=Comparator(), Combine combine=Combine())
Merge two sorted ranges and add all items comparing equal.
void p_write_finished(double now)
Definition: iostats.cpp:296
void write_canceled(const size_t size_)
Definition: iostats.cpp:62
double p_ios_
Definition: iostats.hpp:339
void write_finished()
Definition: iostats.cpp:73
foxxll::stats_data begin_
initial io-stats
Definition: iostats.hpp:668
double p_reads_
seconds spent in parallel io
Definition: iostats.hpp:489
static double timestamp()
Returns number of seconds since the epoch, high resolution.
Definition: timer.hpp:36
int acc_wait_write_
Definition: iostats.hpp:356
void p_read_started(double now)
Definition: iostats.cpp:314
double p_writes_
Definition: iostats.hpp:335
void wait_started(wait_op_type wait_op_)
Definition: iostats.cpp:217
double read_time_
seconds spent in operations
Definition: iostats.hpp:257
double p_wait_write_
Definition: iostats.hpp:353
void to_ostream(std::ostream &o, const std::string line_prefix="") const
Definition: iostats.cpp:663
double write_time_
Definition: iostats.hpp:55
double p_wait_read_
Definition: iostats.hpp:351
external_size_type get_read_bytes() const
Definition: iostats.cpp:526
list x
Definition: gen_data.py:39
file_stats(unsigned int device_id)
construct zero initialized
Definition: iostats.cpp:35
double t_wait
seconds spent waiting for completion of I/O operations
Definition: iostats.hpp:492
static std::string add_IEC_binary_multiplier(const external_size_type number, const std::string &unit="")
Definition: iostats.hpp:643
unsigned write_count_
Definition: iostats.hpp:51
double p_begin_read_
start time of parallel operation
Definition: iostats.hpp:337
void read_started(const size_t size_, double now=0.0)
Definition: iostats.cpp:97
double get_wait_write_time() const
Definition: iostats.cpp:658
unsigned device_id_
device id
Definition: iostats.hpp:251
std::vector< file_stats_data > file_stats_data_list_
list of individual file statistics.
Definition: iostats.hpp:498
std::list< file_stats > file_stats_list_
Definition: iostats.hpp:328
stats_data operator+(const stats_data &a) const
Definition: iostats.cpp:443
std::basic_string< char, std::char_traits< char >, Allocator< char > > string
string with Manager tracking
Definition: allocator.hpp:220
stats_data operator-(const stats_data &a) const
Definition: iostats.cpp:467
void p_write_started(double now)
Definition: iostats.cpp:278
double get_io_wait_time() const
Definition: iostats.cpp:648
static instance_pointer get_instance()
Definition: singleton.hpp:44
unsigned get_device_id() const
Definition: iostats.hpp:281
stats_data::summary< double > get_pread_speed_summary() const
Definition: iostats.cpp:612
double p_begin_wait_
Definition: iostats.hpp:350
double get_elapsed_time() const
Definition: iostats.hpp:620
external_size_type read_bytes_
number of bytes read/written
Definition: iostats.hpp:53
double get_pwrite_time() const
Definition: iostats.cpp:593
static uint_pair min()
return an uint_pair instance containing the smallest value possible
Definition: uint_types.hpp:217
unsigned read_count_
number of operations: read/write
Definition: iostats.hpp:51
double p_reads_
seconds spent in parallel operations
Definition: iostats.hpp:335
stats_data::summary< double > get_write_time_summary() const
Definition: iostats.cpp:579
stats_data::summary< double > get_read_speed_summary() const
Definition: iostats.cpp:603
#define FOXXLL_THROW_IF(expr, exception_type, error_message)
Throws exception_type if (expr) with "Error in [function] : [error_message]".
unsigned get_read_count() const
Definition: iostats.cpp:496
double p_begin_wait_read_
Definition: iostats.hpp:352
void read_finished()
Definition: iostats.cpp:126
stats_data::summary< double > get_write_speed_summary() const
Definition: iostats.cpp:621
std::mutex read_mutex_
Definition: iostats.hpp:358
double t_wait_write_
Definition: iostats.hpp:493
size_t num_files() const
Returns the number of file_stats_data objects.
Definition: iostats.cpp:491
void read_canceled(const size_t size_)
Definition: iostats.cpp:115
void wait_finished(wait_op_type wait_op_)
Definition: iostats.cpp:244
stats()
private construction from singleton
Definition: iostats.cpp:196
stats_data::summary< double > get_pio_speed_summary() const
Definition: iostats.cpp:639
stats_data::summary< external_size_type > get_write_bytes_summary() const
Definition: iostats.cpp:549
file_stats_data operator-(const file_stats_data &a) const
Definition: iostats.cpp:173
void write_op_finished(const size_t size_, double duration)
Definition: iostats.cpp:88
double p_waits_
Definition: iostats.hpp:349
stats_data::summary< double > get_read_time_summary() const
Definition: iostats.cpp:564
unsigned get_write_count() const
Definition: iostats.cpp:511
external_size_type read_bytes_
number of bytes read/written
Definition: iostats.hpp:255
stats_data::summary< external_size_type > get_read_bytes_summary() const
Definition: iostats.cpp:533
double read_time_
seconds spent in operations
Definition: iostats.hpp:55
double t_wait_read_
Definition: iostats.hpp:351
double get_pio_time() const
Definition: iostats.cpp:598
double p_begin_write_
Definition: iostats.hpp:337
std::string format_iec_units(uint64_t number, int precision)
Format number as something like 1 TiB.
double t_waits_
Definition: iostats.hpp:349
stats_data::summary< double > get_pwrite_speed_summary() const
Definition: iostats.cpp:630
double get_read_time() const
Definition: iostats.cpp:558
stats_data::summary< unsigned > get_write_count_summary() const
Definition: iostats.cpp:517
uint64_t external_size_type
Definition: types.hpp:27
std::string message_
message
Definition: iostats.hpp:664
double get_wait_read_time() const
Definition: iostats.cpp:653
stats_data::summary< unsigned > get_read_count_summary() const
Definition: iostats.cpp:502
double t_wait_write_
Definition: iostats.hpp:353
external_size_type get_write_bytes() const
Definition: iostats.cpp:542
file_stats * create_file_stats(unsigned device_id)
Definition: iostats.cpp:350