Skip to content

Commit

Permalink
Improve logging of info messages
Browse files Browse the repository at this point in the history
  • Loading branch information
@tonyelewis
tonyelewis committed Nov 24, 2017
1 parent 91aa61a commit f146c8c
Show file tree
Hide file tree
Showing 5 changed files with 73 additions and 37 deletions.
6 changes: 6 additions & 0 deletions source/executables/cath_refine_align/cath_refine_align.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,8 @@
/// You should have received a copy of the GNU General Public License
/// along with this program. If not, see <http://www.gnu.org/licenses/>.

#include <boost/log/trivial.hpp>

#include "cath_refine_align/cath_align_refiner.hpp"
#include "cath_refine_align/options/cath_refine_align_options.hpp"
#include "chopping/domain/domain.hpp"
Expand All @@ -27,6 +29,9 @@ using namespace cath::common;
using namespace cath::opts;
using namespace std;

using boost::log::trivial::info;
using boost::log::trivial::severity;

namespace cath {

/// \brief A concrete program_exception_wrapper that implements do_run_program() to parse the options and then pass them to cath_align_refiner::refine()
Expand All @@ -40,6 +45,7 @@ namespace cath {
/// \brief Parse the options and then pass them to cath_refine_alignr::superpose()
void do_run_program(int argc, char * argv[]) final {
const auto the_cath_refine_align_options = make_and_parse_options<cath_refine_align_options>( argc, argv );
get_sink_ptr()->set_filter( severity >= info );
cath_align_refiner::refine(the_cath_refine_align_options);
}
};
Expand Down
5 changes: 4 additions & 1 deletion source/executables/cath_ssap/cath_ssap.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,6 @@
/// You should have received a copy of the GNU General Public License
/// along with this program. If not, see <http://www.gnu.org/licenses/>.

#include <boost/log/expressions.hpp>
#include <boost/log/trivial.hpp>

#include "chopping/domain/domain.hpp"
Expand All @@ -30,6 +29,7 @@ using namespace cath::common;
using namespace cath::opts;
using namespace std;

using boost::log::trivial::info;
using boost::log::trivial::severity;
using boost::log::trivial::trace;

Expand All @@ -52,6 +52,9 @@ namespace cath {
// get_sink_ptr()->set_filter( severity >= debug );
get_sink_ptr()->set_filter( severity >= trace );
}
else {
get_sink_ptr()->set_filter( severity >= info );
}

run_ssap( the_cath_ssap_options );
}
Expand Down
6 changes: 6 additions & 0 deletions source/executables/cath_superpose/cath_superpose.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,8 @@
/// You should have received a copy of the GNU General Public License
/// along with this program. If not, see <http://www.gnu.org/licenses/>.

#include <boost/log/trivial.hpp>

#include "cath_superpose/cath_superposer.hpp"
#include "cath_superpose/options/cath_superpose_options.hpp"
#include "chopping/domain/domain.hpp"
Expand All @@ -27,6 +29,9 @@ using namespace cath::common;
using namespace cath::opts;
using namespace std;

using boost::log::trivial::info;
using boost::log::trivial::severity;

namespace cath {

/// \brief A concrete program_exception_wrapper that implements do_run_program() to parse the options and then pass them to cath_superposer::superpose()
Expand All @@ -40,6 +45,7 @@ namespace cath {
/// \brief Parse the options and then pass them to cath_superposer::superpose()
void do_run_program(int argc, char * argv[]) final {
const auto the_cath_superpose_options = make_and_parse_options<cath_superpose_options>( argc, argv );
get_sink_ptr()->set_filter( severity >= info );
cath_superposer::superpose(the_cath_superpose_options);
}
};
Expand Down
37 changes: 29 additions & 8 deletions source/uni/acquirer/alignment_acquirer/do_the_ssaps_alignment_acquirer.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -38,6 +38,7 @@
#include "common/file/open_fstream.hpp"
#include "common/file/slurp.hpp"
#include "common/file/spew.hpp"
#include "common/matrix/matrix_index.hpp"
#include "file/strucs_context.hpp"
#include "ssap/options/cath_ssap_options.hpp"
#include "ssap/ssap.hpp"
Expand All @@ -61,6 +62,7 @@ using boost::filesystem::temp_directory_path;
using boost::format;
using boost::irange;
using std::ofstream;
using std::max;
using std::pair;
using std::string;
using std::unique_ptr;
Expand All @@ -75,6 +77,8 @@ unique_ptr<alignment_acquirer> do_the_ssaps_alignment_acquirer::do_clone() const
/// \brief Run the necessary cath-ssaps and then use them to get the alignment and spanning tree
pair<alignment, size_size_pair_vec> do_the_ssaps_alignment_acquirer::do_get_alignment_and_spanning_tree(const strucs_context &arg_strucs_context ///< The details of the structures for which the alignment and spanning tree is required
) const {
using std::to_string;

// Get the directory in which the cath-ssaps should be done
const path ssaps_dir = get_directory_of_joy().value_or(
make_temp_dir_for_doing_ssaps( arg_strucs_context )
Expand All @@ -94,15 +98,29 @@ pair<alignment, size_size_pair_vec> do_the_ssaps_alignment_acquirer::do_get_alig

// Perform any necessary cath-ssaps
path_vec scores_files;
BOOST_LOG_TRIVIAL( info ) << "About to check for and possibly run cath-ssaps in directory " << ssaps_dir;
for (const size_t &struc_1_index : indices( size( arg_strucs_context ) ) ) {
for (const size_t &struc_2_index : irange( struc_1_index + 1, size( arg_strucs_context ) ) ) {
const size_t num_strucs = size( arg_strucs_context );
const size_t num_ssaps = ( num_strucs * ( max( 1_z, num_strucs ) - 1_z ) ) / 2_z;
const string num_str = to_string( num_ssaps );
const size_t num_str_width = num_str.length();
const string num_str_width_str = "%" + to_string( num_str_width ) + "d";
BOOST_LOG_TRIVIAL( info ) << "About to check for and possibly run " << num_ssaps << " cath-ssaps in directory " << ssaps_dir;
for (const size_t &struc_1_index : indices( num_strucs ) ) {
for (const size_t &struc_2_index : irange( struc_1_index + 1, num_strucs ) ) {

const size_t comp_ctr_offset_1 = get_zero_index_of_strict_upper_half_matrix(
struc_1_index,
struc_2_index,
num_strucs
) + 1;
const string progress_str = ( format( num_str_width_str ) % comp_ctr_offset_1 ).str()
+ "/"
+ num_str;

// \TODO: Abstract out functions for making these standard file names
const string file_id_1 = get_domain_or_specified_or_name_from_acq( arg_strucs_context.get_name_sets()[ struc_1_index ] );
const string file_id_2 = get_domain_or_specified_or_name_from_acq( arg_strucs_context.get_name_sets()[ struc_2_index ] );
const path scores_file = ssaps_dir / ( file_id_1 + file_id_2 + ".scores" );
const path alnmnt_file = ssaps_dir / ( file_id_1 + file_id_2 + ".list" );
const string id_1 = get_domain_or_specified_or_name_from_acq( arg_strucs_context.get_name_sets()[ struc_1_index ] );
const string id_2 = get_domain_or_specified_or_name_from_acq( arg_strucs_context.get_name_sets()[ struc_2_index ] );
const path scores_file = ssaps_dir / ( id_1 + id_2 + ".scores" );
const path alnmnt_file = ssaps_dir / ( id_1 + id_2 + ".list" );

scores_files.push_back( scores_file );

Expand All @@ -127,7 +145,7 @@ pair<alignment, size_size_pair_vec> do_the_ssaps_alignment_acquirer::do_get_alig
cath_ssap_args.push_back( sillitoe_chopping_format{}.write_domain( *opt_domain ) );
}
}
BOOST_LOG_TRIVIAL( info ) << "Running: " << join( cath_ssap_args, " " ) << " and writing scores to " << scores_file;
BOOST_LOG_TRIVIAL( info ) << "[" << progress_str << "] Running : " << join( cath_ssap_args, " " ) << " and writing scores to " << scores_file;
ofstream out_scores_ofstream;
open_ofstream( out_scores_ofstream, scores_file );
run_ssap(
Expand All @@ -138,6 +156,9 @@ pair<alignment, size_size_pair_vec> do_the_ssaps_alignment_acquirer::do_get_alig
);
out_scores_ofstream.close();
}
else {
BOOST_LOG_TRIVIAL( info ) << "[" << progress_str << "] Skipping " << id_1 << " versus " << id_2 << " - non-empty data files already exist";
}
}
}

Expand Down
56 changes: 28 additions & 28 deletions source/uni/ssap/ssap.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -518,16 +518,16 @@ void cath::align_proteins(const protein &arg_protein_a, ///<
const old_ssap_options_block &arg_ssap_options, ///< The old_ssap_options_block to specify how things should be done
const data_dirs_spec &arg_data_dirs ///< The data directories from which data should be read
) {
BOOST_LOG_TRIVIAL( info ) << "Function: alnseq";
BOOST_LOG_TRIVIAL( debug ) << "Function: alnseq";

// Set alignment options
global_res_score = false;
global_align_pass = false;
global_gap_penalty = 5;
global_window = max( arg_protein_a.get_num_sec_strucs(), arg_protein_b.get_num_sec_strucs() );

BOOST_LOG_TRIVIAL( info ) << "Function: alnseq: seqa->nsec=" << arg_protein_a.get_num_sec_strucs();
BOOST_LOG_TRIVIAL( info ) << "Function: alnseq: seqb->nsec=" << arg_protein_b.get_num_sec_strucs();
BOOST_LOG_TRIVIAL( debug ) << "Function: alnseq: seqa->nsec=" << arg_protein_a.get_num_sec_strucs();
BOOST_LOG_TRIVIAL( debug ) << "Function: alnseq: seqb->nsec=" << arg_protein_b.get_num_sec_strucs();

ssap_scores fast_ssap_scores;
if ( !arg_ssap_options.get_slow_ssap_only() ) {
Expand All @@ -544,7 +544,7 @@ void cath::align_proteins(const protein &arg_protein_a, ///<

// Re-run with increased window and torsional angle cutoffs, if not a great alignment
if ( first_score < arg_ssap_options.get_max_score_to_fast_ssap_rerun() && ! has_clique_file( arg_ssap_options ) ) {
BOOST_LOG_TRIVIAL( info ) << "Dist is: " << arg_ssap_options.get_max_score_to_fast_ssap_rerun() << " Removing cutoffs....";
BOOST_LOG_TRIVIAL( debug ) << "Dist is: " << arg_ssap_options.get_max_score_to_fast_ssap_rerun() << " Removing cutoffs....";

--global_run_counter;

Expand All @@ -561,9 +561,9 @@ void cath::align_proteins(const protein &arg_protein_a, ///<
const double second_score = fast_ssap_scores.get_ssap_score_over_larger();

// Re-run original alignment if it doesn't give a better score
BOOST_LOG_TRIVIAL( info ) << "Comparing score " << setprecision(30) << second_score << " with " << first_score;
BOOST_LOG_TRIVIAL( debug ) << "Comparing score " << setprecision(30) << second_score << " with " << first_score;
if (second_score <= first_score) {
BOOST_LOG_TRIVIAL( info ) << "Reverting back to original Fast SSAP....";
BOOST_LOG_TRIVIAL( debug ) << "Reverting back to original Fast SSAP....";

--global_run_counter;

Expand All @@ -589,13 +589,13 @@ void cath::align_proteins(const protein &arg_protein_a, ///<
// Don't run slow ssap if clique information is used
const bool run_slow_ssap = ( ! has_clique_file( arg_ssap_options ) && ! fast_ssap_result_is_close );
if ( fast_ssap_result_is_close ) {
BOOST_LOG_TRIVIAL( info ) << "Not running slow SSAP. Cutoff: " << arg_ssap_options.get_max_score_to_slow_ssap_rerun()
BOOST_LOG_TRIVIAL( debug ) << "Not running slow SSAP. Cutoff: " << arg_ssap_options.get_max_score_to_slow_ssap_rerun()
<< " Score: " << fast_ssap_scores.get_ssap_score_over_smaller();
}

// RUN SLOW SSAP - START
if ( run_slow_ssap ) {
BOOST_LOG_TRIVIAL( info ) << "Function: alnseq: slow_ssap";
BOOST_LOG_TRIVIAL( debug ) << "Function: alnseq: slow_ssap";

// v1.14 JEB
++global_run_counter;
Expand All @@ -615,7 +615,7 @@ void cath::align_proteins(const protein &arg_protein_a, ///<

// Perform two residue alignment passes
for (const size_t &pass_ctr : { 1_z, 2_z } ) {
BOOST_LOG_TRIVIAL( info ) << "Function: alnseq: pass=" << pass_ctr;
BOOST_LOG_TRIVIAL( debug ) << "Function: alnseq: pass=" << pass_ctr;

global_align_pass = ( pass_ctr > 1 );
if (pass_ctr == 1 || (pass_ctr == 2 && global_res_score)) {
Expand All @@ -637,8 +637,8 @@ ssap_scores cath::fast_ssap(const protein &arg_protein_a, ///
) {
ssap_scores new_ssap_scores;

BOOST_LOG_TRIVIAL( info ) << "Fast SSAP: dtot=" << global_res_sim_cutoff << " window_add=" << global_window_add;
BOOST_LOG_TRIVIAL( info ) << "Function: fast_ssap: fast_ssap";
BOOST_LOG_TRIVIAL( debug ) << "Fast SSAP: dtot=" << global_res_sim_cutoff << " window_add=" << global_window_add;
BOOST_LOG_TRIVIAL( debug ) << "Function: fast_ssap: fast_ssap";

// Perform secondary structure alignment
++global_run_counter;
Expand All @@ -661,7 +661,7 @@ ssap_scores cath::fast_ssap(const protein &arg_protein_a, ///

// Perform two residue alignment passes
for (const size_t &pass_ctr : { 1_z, 2_z } ) {
BOOST_LOG_TRIVIAL( info ) << "Function: fast_ssap: pass=" << pass_ctr;
BOOST_LOG_TRIVIAL( debug ) << "Function: fast_ssap: pass=" << pass_ctr;
global_align_pass = ( pass_ctr > 1 );
if ( pass_ctr == 1 || ( pass_ctr == 2 && global_res_score ) ) {
const pair<ssap_scores, alignment> tmp_scores_and_aln = compare( arg_protein_a, arg_protein_b, pass_ctr, residue_querier(), arg_ssap_options, arg_data_dirs, sec_struc_alignment );
Expand Down Expand Up @@ -697,12 +697,12 @@ pair<ssap_scores, alignment> cath::compare(const protein &arg_pr
global_upper_ss_mask_matrix.resize ( length_b + 1, length_a + global_window + 1, false );
global_lower_mask_matrix.resize ( length_b + 1, length_a + global_window + 1, false );

BOOST_LOG_TRIVIAL( info ) << "Function: compare";
BOOST_LOG_TRIVIAL( info ) << "Function: compare: [aligning " << entry_plural_name << "]";
BOOST_LOG_TRIVIAL( info ) << "Function: compare: pass=" << arg_pass_ctr;
BOOST_LOG_TRIVIAL( debug ) << "Function: compare";
BOOST_LOG_TRIVIAL( debug ) << "Function: compare: [aligning " << entry_plural_name << "]";
BOOST_LOG_TRIVIAL( debug ) << "Function: compare: pass=" << arg_pass_ctr;

if ( ! res_not_ss__hacky || arg_pass_ctr == 1 ) {
BOOST_LOG_TRIVIAL( info ) << "Function: compare: [aligning " << entry_plural_name << "] Initialise global_lower_mask_matrix and global_upper_ss_mask_matrix";
BOOST_LOG_TRIVIAL( debug ) << "Function: compare: [aligning " << entry_plural_name << "] Initialise global_lower_mask_matrix and global_upper_ss_mask_matrix";
// Each of these matrices is currently indexed with offset-1
//
// \todo Shift each of these matrices to not use offset-1 and remove the extra " + 1"
Expand Down Expand Up @@ -730,11 +730,11 @@ pair<ssap_scores, alignment> cath::compare(const protein &arg_pr
//
// \todo Shift each of these matrices to not use offset-1 and remove the extra " + 1"
// from these lines
BOOST_LOG_TRIVIAL( info ) << "Function: compare: [aligning " << entry_plural_name << "] Initialise global_lower_mask_matrix and global_upper_ss_mask_matrix";
BOOST_LOG_TRIVIAL( debug ) << "Function: compare: [aligning " << entry_plural_name << "] Initialise global_lower_mask_matrix and global_upper_ss_mask_matrix";
global_upper_score_matrix.assign ( length_b + 1, length_a + global_window + 1, 0 );
// global_upper_res_mask_matrix.assign( length_b + 1, length_a + global_window + 1, false );

BOOST_LOG_TRIVIAL( info ) << "Function: compare: [aligning " << entry_plural_name << "] score_matrix twice";
BOOST_LOG_TRIVIAL( debug ) << "Function: compare: [aligning " << entry_plural_name << "] score_matrix twice";

// Call score_matrix() to populate
populate_upper_score_matrix(arg_protein_a, arg_protein_b, arg_entry_querier, global_align_pass);
Expand Down Expand Up @@ -825,7 +825,7 @@ protein cath::read_protein_data_from_ssap_options_files(const data_dirs_spec
for (const data_file_path_pair &filename_and_data_file : filename_of_data_file) {
const string file_str = to_lower_copy( lexical_cast<string>( filename_and_data_file.first ) );
const string right_padded_file_str = string( max_data_file_str_length() - file_str.length(), ' ' );
BOOST_LOG_TRIVIAL( info ) << "Loading " << file_str << right_padded_file_str << " from " << filename_and_data_file.second;
BOOST_LOG_TRIVIAL( debug ) << "Loading " << file_str << right_padded_file_str << " from " << filename_and_data_file.second;
}

// Create a protein object from the name, wolf file and sec file
Expand Down Expand Up @@ -1019,7 +1019,7 @@ void cath::set_mask_matrix(const protein &arg_protein_a, ///< The f
*last_present_a_opt + 2, // ( + 1 to go from position to size and +1 because it will be indexed offset_1)
false
);
BOOST_LOG_TRIVIAL( debug ) << "Setting secondary structure alignment : " << *arg_opt_ss_alignment;;
BOOST_LOG_TRIVIAL( trace ) << "Setting secondary structure alignment : " << *arg_opt_ss_alignment;;
for (const size_t &alignment_ctr : indices( arg_opt_ss_alignment->length() ) ) {
if ( has_both_positions_of_index( *arg_opt_ss_alignment, alignment_ctr ) ) {
sec_struc_match_matrix.set(
Expand Down Expand Up @@ -1359,7 +1359,7 @@ void cath::populate_upper_score_matrix(const protein &arg_protein_a, /
+ "; pass "
+ booled_to_string( arg_align_pass )
+ "), ";
BOOST_LOG_TRIVIAL( debug ) << msg_context_prfx
BOOST_LOG_TRIVIAL( trace ) << msg_context_prfx
<< "compared "
<< num_actual_upper_cell_comps
<< " residue pairs out of a possible "
Expand Down Expand Up @@ -1798,7 +1798,7 @@ bool cath::save_ssap_scores(const alignment &arg_alignment, ///
const old_ssap_options_block &arg_ssap_options, ///< The old_ssap_options_block to specify how things should be done
const data_dirs_spec &arg_data_dirs ///< The data directories from which data should be read
) {
BOOST_LOG_TRIVIAL( info ) << "Function: save_ssap_scores";
BOOST_LOG_TRIVIAL( debug ) << "Function: save_ssap_scores";

// Select get_ssap_score_over_smaller if a local score is needed, or get_ssap_score_over_larger otherwise
const double select_score = arg_ssap_options.get_use_local_ssap_score() ? arg_ssap_scores.get_ssap_score_over_smaller()
Expand Down Expand Up @@ -1879,7 +1879,7 @@ void cath::save_zero_scores(const protein &arg_protein_a, ///< The first prot
const protein &arg_protein_b, ///< The second protein
const ptrdiff_t &arg_run_counter ///< The run counter
) {
BOOST_LOG_TRIVIAL( info ) << "Function: save_zero_scores()";
BOOST_LOG_TRIVIAL( debug ) << "Function: save_zero_scores()";

if ( arg_run_counter == 1 ) {
snprintf(
Expand Down Expand Up @@ -2076,9 +2076,9 @@ ssap_scores cath::plot_aln(const protein &arg_protein_a, ///
global_score_run2 = select_score;
}

BOOST_LOG_TRIVIAL( info ) << "Function: plot_aln: score_run1 = " << fixed << setprecision(3) << global_score_run1;
BOOST_LOG_TRIVIAL( info ) << "Function: plot_aln: score_run2 = " << fixed << setprecision(3) << global_score_run2;
BOOST_LOG_TRIVIAL( info ) << "Function: plot_aln: r_fast = " << boolalpha << global_doing_fast_ssap;;
BOOST_LOG_TRIVIAL( debug ) << "Function: plot_aln: score_run1 = " << fixed << setprecision(3) << global_score_run1;
BOOST_LOG_TRIVIAL( debug ) << "Function: plot_aln: score_run2 = " << fixed << setprecision(3) << global_score_run2;
BOOST_LOG_TRIVIAL( debug ) << "Function: plot_aln: r_fast = " << boolalpha << global_doing_fast_ssap;;

// A decision is made here about whether to write an alignment file, based on
// the score of the alignment. However, this is inconsistent with save_ssap_scores
Expand All @@ -2096,15 +2096,15 @@ ssap_scores cath::plot_aln(const protein &arg_protein_a, ///
out_score = global_score_run2;
}
if (out_score > -1.0) {
BOOST_LOG_TRIVIAL( info ) << "Function: plot_aln: printing alignment (r_fast == 1) || (!r_fast && score_run2 > score_run1)";
BOOST_LOG_TRIVIAL( debug ) << "Function: plot_aln: printing alignment (r_fast == 1) || (!r_fast && score_run2 > score_run1)";

// Prevent writing if score isn't high enough
if (score_is_high_enough != (out_score >= arg_ssap_options.get_min_score_for_writing_files())) {
BOOST_THROW_EXCEPTION(out_of_range_exception("Code is inconsistent about what score is high enough"));
}

if (score_is_high_enough) {
BOOST_LOG_TRIVIAL( info ) << "Function: print_aln"
BOOST_LOG_TRIVIAL( debug ) << "Function: print_aln"
<< " "
<< to_string( arg_protein_a.get_name_set() )
<< " "
Expand Down

0 comments on commit f146c8c

Please sign in to comment.