abidw: Improve timing logs during self-comparison
Commit Message
Hello,
When running abidw with --abidiff and --stats options, the timing
information was incomplete. This patch adds more detailed timing
measurements for each phase of the self-comparison process, including
writing the ABIXML to disk, reading it back, comparing the ABIs, and
emitting the report.
* tools/abidw.cc (perform_self_comparison): Add timing log for
writing ABIXML file to disk. Add timing log for reading ABIXML
back from disk with clearer message. Pass do_log && show_stats to
diff_context::do_log. Add timing log for comparing the two ABIs,
detecting potential changes, analyzing changes and emitting
report. Also add log message when no error is detected.
(load_corpus_and_write_abixml): Remove redundant "reset reader
ELF" log message. Remove early reader.reset() call and its
associated timing log because that might take a lot of time for
huge binaries.
(load_kernel_corpus_group_and_write_abixml): Change log message
from "going to build" to "building" for consistency.
Signed-off-by: Dodji Seketeli <dodji@redhat.com>
Applied to the master branch.
---
tools/abidw.cc | 103 ++++++++++++++++++++++++++++++++++++++-----------
1 file changed, 81 insertions(+), 22 deletions(-)
@@ -358,12 +358,29 @@ perform_self_comparison(const write_context_sptr& write_ctxt,
set_ostream(*write_ctxt, tmp_file->get_stream());
corpus_group_sptr corp_group = is_corpus_group(corp);
+ if (opts.do_log)
+ {
+ emit_prefix(argv[0], cerr)
+ << "Writing ABIXML file to disk at '"
+ << tmp_file->get_path()
+ << "' ..."
+ << std::endl;
+ t.start();
+ }
+
if (corp_group)
write_corpus_group(*write_ctxt, corp_group, 0);
else
write_corpus(*write_ctxt, corp, 0);
tmp_file->get_stream().flush();
+ if (opts.do_log)
+ {
+ t.stop();
+ emit_prefix(argv[0], cerr)
+ << " wrote ABIXML file to disk in " << t << "\n";
+ }
+
#ifdef WITH_DEBUG_SELF_COMPARISON
if (opts.debug_abidiff)
{
@@ -380,7 +397,13 @@ perform_self_comparison(const write_context_sptr& write_ctxt,
load_canonical_type_ids(*rdr, opts.type_id_file_path);
#endif
- t.start();
+ if (opts.do_log)
+ {
+ emit_prefix(argv[0], cerr)
+ << "Reading ABIXML back from disk ...\n";
+ t.start();
+ }
+
fe_iface::status sts;
corpus_sptr corp2;
corpus_group_sptr corp_group2;
@@ -390,10 +413,12 @@ perform_self_comparison(const write_context_sptr& write_ctxt,
else
corp2 = rdr->read_corpus(sts);
- t.stop();
if (opts.do_log)
- emit_prefix(argv[0], cerr)
- << "Read corpus in: " << t << "\n";
+ {
+ t.stop();
+ emit_prefix(argv[0], cerr)
+ << "Read back from disk corpus in: " << t << "\n";
+ }
#ifdef WITH_DEBUG_SELF_COMPARISON
if (opts.debug_abidiff
@@ -412,28 +437,71 @@ perform_self_comparison(const write_context_sptr& write_ctxt,
diff_context_sptr ctxt(new diff_context);
set_diff_context(ctxt);
ctxt->show_locs(opts.show_locs);
- t.start();
+ ctxt->do_log(opts.do_log && opts.show_stats);
+
+ if (opts.do_log)
+ {
+ emit_prefix(argv[0], cerr)
+ << "comparing the two ABIs ...\n";
+ t.start();
+ }
+
corpus_diff_sptr diff =
corp_group2
? compute_diff(corp_group, corp_group2, ctxt)
: compute_diff(corp, corp2, ctxt);
- t.stop();
if (opts.do_log)
- emit_prefix(argv[0], cerr)
- << "computed diff in: " << t << "\n";
+ {
+ t.stop();
+ emit_prefix(argv[0], cerr)
+ << "computed diff in: " << t << "\n\n";
+
+ emit_prefix(argv[0], cerr)
+ << "detecting potential changes ...\n";
+ t.start();
+ }
bool has_error = diff->has_changes();
+
+ if (opts.do_log)
+ {
+ t.stop();
+ emit_prefix(argv[0], cerr)
+ << "detected "
+ << (has_error ? string("changes ") : string("no change "))
+ << "in "
+ << t
+ << std::endl;
+ }
+
if (has_error)
{
- t.start();
+ if (opts.do_log)
+ {
+ emit_prefix(argv[0], cerr)
+ << "analyzing changes and emitting report ..." << std::endl;
+ t.start();
+ }
+
diff->report(cerr);
- t.stop();
+
if (opts.do_log)
- emit_prefix(argv[0], cerr)
- << "emitted report in: " << t << "\n";
+ {
+ t.stop();
+ emit_prefix(argv[0], cerr)
+ << "analyzed changes and emitted report in " << t << std::endl;
+ }
+
return 1;
}
+ else
+ {
+ if (opts.do_log)
+ emit_prefix(argv[0], cerr)
+ << "detected no error"
+ << std::endl;
+ }
return 0;
}
@@ -534,10 +602,6 @@ load_corpus_and_write_abixml(char* argv[],
emit_prefix(argv[0], cerr)
<< "read corpus from elf file in: " << t << "\n";
- if (opts.do_log)
- emit_prefix(argv[0], cerr)
- << "reset reader ELF in: " << t << "\n";
-
// If we couldn't create a corpus, emit some (hopefully) useful
// diagnostics and return an error.
if (!corp)
@@ -652,11 +716,6 @@ load_corpus_and_write_abixml(char* argv[],
opts.added_bins_dirs);
}
- // Clear some resources to gain back some space.
- t.start();
- reader.reset();
- t.stop();
-
// Now create a write context and write out an ABI XML description
// of the read corpus.
t.start();
@@ -755,7 +814,7 @@ load_kernel_corpus_group_and_write_abixml(char* argv[],
if (opts.do_log)
emit_prefix(argv[0], cerr)
- << "going to build ABI representation of the Linux Kernel ...\n";
+ << "building ABI representation of the Linux Kernel ...\n";
global_timer.start();
t.start();