Merge pull request seqan#229 from smehringer/timers

[FEATURE] Add --timing-output and Output layout timings.

include/chopper/configuration.hpp

@@ -29,6 +29,9 @@ struct configuration
 
     //!\brief Internal parameter that triggers some verbose debug output.
     bool debug{false};
+
+    //!\brief If specified, layout timings are written to the specified file.
+    std::filesystem::path output_timings{};
     //!\}
 
     /*!\name Configuration of size estimates (chopper::count)

src/layout/execute.cpp

@@ -61,6 +61,11 @@ int execute(chopper::configuration & config, std::vector<std::string> const & fi
     seqan::hibf::layout::layout hibf_layout;
     std::vector<seqan::hibf::sketch::hyperloglog> sketches;
 
+    seqan::hibf::concurrent_timer compute_sketches_timer{};
+    seqan::hibf::concurrent_timer union_estimation_timer{};
+    seqan::hibf::concurrent_timer rearrangement_timer{};
+    seqan::hibf::concurrent_timer dp_algorithm_timer{};
+
     if (config.determine_best_tmax)
     {
         std::tie(hibf_layout, sketches) = determine_best_number_of_technical_bins(config);
@@ -69,8 +74,16 @@ int execute(chopper::configuration & config, std::vector<std::string> const & fi
     {
         std::vector<size_t> kmer_counts;
 
+        compute_sketches_timer.start();
         seqan::hibf::sketch::compute_sketches(config.hibf_config, kmer_counts, sketches);
-        hibf_layout = seqan::hibf::layout::compute_layout(config.hibf_config, kmer_counts, sketches);
+        compute_sketches_timer.stop();
+        dp_algorithm_timer.start();
+        hibf_layout = seqan::hibf::layout::compute_layout(config.hibf_config,
+                                                          kmer_counts,
+                                                          sketches,
+                                                          union_estimation_timer,
+                                                          rearrangement_timer);
+        dp_algorithm_timer.stop();
 
         if (config.output_verbose_statistics)
         {
@@ -98,6 +111,20 @@ int execute(chopper::configuration & config, std::vector<std::string> const & fi
     config.write_to(fout);
     hibf_layout.write_to(fout);
 
+    if (!config.output_timings.empty())
+    {
+        std::ofstream output_stream{config.output_timings};
+        output_stream << std::fixed << std::setprecision(2);
+        output_stream << "sketching_in_seconds\t"
+                      << "layouting_in_seconds\t"
+                      << "union_estimation_in_seconds\t"
+                      << "rearrangement_in_seconds\n";
+        output_stream << compute_sketches_timer.in_seconds() << '\t';
+        output_stream << dp_algorithm_timer.in_seconds() << '\t';
+        output_stream << union_estimation_timer.in_seconds() << '\t';
+        output_stream << rearrangement_timer.in_seconds() << '\t';
+    }
+
     return 0;
 }
 

src/set_up_parser.cpp

@@ -78,6 +78,12 @@ void set_up_parser(sharg::parser & parser, configuration & config)
                 "accuracy.",
             .default_message = "k-mer size",
         });
+    parser.add_option(config.output_timings,
+                      sharg::config{.short_id = '\0',
+                                    .long_id = "timing-output",
+                                    .description = "Write time and memory usage to specified file (TSV format). ",
+                                    .default_message = "",
+                                    .validator = sharg::output_file_validator{}});
 
     parser.add_option(
         config.hibf_config.tmax,

test/cli/CMakeLists.txt

@@ -14,3 +14,6 @@ target_use_datasources (cli_chopper_pipeline_test FILES seq1.fa)
 target_use_datasources (cli_chopper_pipeline_test FILES small.fa)
 target_use_datasources (cli_chopper_pipeline_test FILES small2.fa)
 target_use_datasources (cli_chopper_pipeline_test FILES small.split)
+
+add_cli_test (cli_timing_output_test.cpp)
+target_use_datasources (cli_chopper_pipeline_test FILES small.fa)

test/cli/cli_timing_output_test.cpp

@@ -0,0 +1,45 @@
+// ---------------------------------------------------------------------------------------------------
+// Copyright (c) 2006-2023, Knut Reinert & Freie Universität Berlin
+// Copyright (c) 2016-2023, Knut Reinert & MPI für molekulare Genetik
+// This file may be used, modified and/or redistributed under the terms of the 3-clause BSD-License
+// shipped with this file and also available at: https://github.com/seqan/chopper/blob/main/LICENSE.md
+// ---------------------------------------------------------------------------------------------------
+
+#include <gtest/gtest.h>
+
+#include <filesystem>
+#include <fstream>
+#include <string> // strings
+
+#include <seqan3/test/tmp_directory.hpp>
+
+#include "cli_test.hpp"
+
+TEST_F(cli_test, timing_output)
+{
+    std::string const seq_filename = data("small.fa");
+    seqan3::test::tmp_directory tmp_dir{};
+    std::filesystem::path const input_filename{tmp_dir.path() / "data.tsv"};
+    std::filesystem::path const layout_filename{tmp_dir.path() / "output.layout"};
+    std::filesystem::path const timing_filename{tmp_dir.path() / "output.timings"};
+
+    {
+        std::ofstream fout{input_filename};
+        fout << seq_filename << '\n' << seq_filename << '\n' << seq_filename << '\n';
+    }
+
+    cli_test_result result = execute_app("chopper",
+                                         "--input",
+                                         input_filename.c_str(),
+                                         "--output",
+                                         layout_filename.c_str(),
+                                         "--timing-output",
+                                         timing_filename.c_str());
+
+    EXPECT_EQ(result.exit_code, 0);
+    EXPECT_EQ(result.out, std::string{});
+    EXPECT_EQ(result.err, std::string{});
+
+    EXPECT_TRUE(std::filesystem::exists(timing_filename)); // file should have been written
+    // not not check output since it is not relevant how exectly the timings look like
+}