From 0f5634015167b315a8d3ddfc8601abf26e1187f6 Mon Sep 17 00:00:00 2001 From: Stefan Weil Date: Thu, 4 May 2023 21:39:51 +0200 Subject: [PATCH] Improve format of logging from lstmtraining - always use C ("classic") locale - limit output of floating point values to 3 digits - remove unneeded linefeed after log message "wrote checkpoint" Signed-off-by: Stefan Weil --- src/training/lstmtraining.cpp | 6 +- src/training/unicharset/lstmtester.cpp | 14 ++-- src/training/unicharset/lstmtrainer.cpp | 90 ++++++++++++------------- src/training/unicharset/lstmtrainer.h | 17 ++--- unittest/lstm_test.h | 2 +- 5 files changed, 66 insertions(+), 63 deletions(-) diff --git a/src/training/lstmtraining.cpp b/src/training/lstmtraining.cpp index a1068bdb..d1cae301 100644 --- a/src/training/lstmtraining.cpp +++ b/src/training/lstmtraining.cpp @@ -16,6 +16,7 @@ /////////////////////////////////////////////////////////////////////// #include +#include // for std::locale::classic #if defined(__USE_GNU) # include // for feenableexcept #endif @@ -222,9 +223,10 @@ int main(int argc, char **argv) { iteration = trainer.training_iteration()) { trainer.TrainOnLine(&trainer, false); } - std::string log_str; + std::stringstream log_str; + log_str.imbue(std::locale::classic()); trainer.MaintainCheckpoints(tester_callback, log_str); - tprintf("%s\n", log_str.c_str()); + tprintf("%s\n", log_str.str().c_str()); } while (trainer.best_error_rate() > FLAGS_target_error_rate && (trainer.training_iteration() < max_iterations)); tprintf("Finished! Selected model with minimal training error rate (BCER) = %g\n", diff --git a/src/training/unicharset/lstmtester.cpp b/src/training/unicharset/lstmtester.cpp index bd0f222a..052460cf 100644 --- a/src/training/unicharset/lstmtester.cpp +++ b/src/training/unicharset/lstmtester.cpp @@ -16,6 +16,7 @@ /////////////////////////////////////////////////////////////////////// #include "lstmtester.h" +#include // for std::setprecision #include // for std::thread #include "fileio.h" // for LoadFileLinesToStrings @@ -115,14 +116,15 @@ std::string LSTMTester::RunEvalSync(int iteration, const double *training_errors } char_error *= 100.0 / total_pages_; word_error *= 100.0 / total_pages_; - std::string result; + std::stringstream result; + result.imbue(std::locale::classic()); + result << std::fixed << std::setprecision(3); if (iteration != 0 || training_stage != 0) { - result += "At iteration " + std::to_string(iteration); - result += ", stage " + std::to_string(training_stage) + ", "; + result << "At iteration " << iteration + << ", stage " << training_stage << ", "; } - result += "BCER eval=" + std::to_string(char_error); - result += ", BWER eval=" + std::to_string(word_error); - return result; + result << "BCER eval=" << char_error << ", BWER eval=" << word_error; + return result.str(); } // Helper thread function for RunEvalAsync. diff --git a/src/training/unicharset/lstmtrainer.cpp b/src/training/unicharset/lstmtrainer.cpp index 0ebad4de..54b82a61 100644 --- a/src/training/unicharset/lstmtrainer.cpp +++ b/src/training/unicharset/lstmtrainer.cpp @@ -23,6 +23,8 @@ #endif #include +#include // for std::setprecision +#include // for std::locale::classic #include #include "lstmtrainer.h" @@ -305,7 +307,7 @@ bool LSTMTrainer::LoadAllTrainingData(const std::vector &filenames, // Writes checkpoints at appropriate times and builds and returns a log message // to indicate progress. Returns false if nothing interesting happened. bool LSTMTrainer::MaintainCheckpoints(const TestCallback &tester, - std::string &log_msg) { + std::stringstream &log_msg) { PrepareLogMsg(log_msg); double error_rate = CharError(); int iteration = learning_iteration(); @@ -330,35 +332,34 @@ bool LSTMTrainer::MaintainCheckpoints(const TestCallback &tester, std::vector rec_model_data; if (error_rate < best_error_rate_) { SaveRecognitionDump(&rec_model_data); - log_msg += " New best BCER = " + std::to_string(error_rate); - log_msg += UpdateErrorGraph(iteration, error_rate, rec_model_data, tester); + log_msg << " New best BCER = " << error_rate; + log_msg << UpdateErrorGraph(iteration, error_rate, rec_model_data, tester); // If sub_trainer_ is not nullptr, either *this beat it to a new best, or it // just overwrote *this. In either case, we have finished with it. sub_trainer_.reset(); stall_iteration_ = learning_iteration() + kMinStallIterations; if (TransitionTrainingStage(kStageTransitionThreshold)) { - log_msg += - " Transitioned to stage " + std::to_string(CurrentTrainingStage()); + log_msg << " Transitioned to stage " << CurrentTrainingStage(); } SaveTrainingDump(NO_BEST_TRAINER, *this, &best_trainer_); if (error_rate < error_rate_of_last_saved_best_ * kBestCheckpointFraction) { std::string best_model_name = DumpFilename(); if (!SaveDataToFile(best_trainer_, best_model_name.c_str())) { - log_msg += " failed to write best model:"; + log_msg << " failed to write best model:"; } else { - log_msg += " wrote best model:"; + log_msg << " wrote best model:"; error_rate_of_last_saved_best_ = best_error_rate_; } - log_msg += best_model_name; + log_msg << best_model_name; } } else if (error_rate > worst_error_rate_) { SaveRecognitionDump(&rec_model_data); - log_msg += " New worst BCER = " + std::to_string(error_rate); - log_msg += UpdateErrorGraph(iteration, error_rate, rec_model_data, tester); + log_msg << " New worst BCER = " << error_rate; + log_msg << UpdateErrorGraph(iteration, error_rate, rec_model_data, tester); if (worst_error_rate_ > best_error_rate_ + kMinDivergenceRate && best_error_rate_ < kMinStartedErrorRate && !best_trainer_.empty()) { // Error rate has ballooned. Go back to the best model. - log_msg += "\nDivergence! "; + log_msg << "\nDivergence! "; // Copy best_trainer_ before reading it, as it will get overwritten. std::vector revert_data(best_trainer_); if (ReadTrainingDump(revert_data, *this)) { @@ -382,34 +383,33 @@ bool LSTMTrainer::MaintainCheckpoints(const TestCallback &tester, std::vector checkpoint; if (!SaveTrainingDump(FULL, *this, &checkpoint) || !SaveDataToFile(checkpoint, checkpoint_name_.c_str())) { - log_msg += " failed to write checkpoint."; + log_msg << " failed to write checkpoint."; } else { - log_msg += " wrote checkpoint."; + log_msg << " wrote checkpoint."; } } - log_msg += "\n"; return result; } // Builds a string containing a progress message with current error rates. -void LSTMTrainer::PrepareLogMsg(std::string &log_msg) const { +void LSTMTrainer::PrepareLogMsg(std::stringstream &log_msg) const { LogIterations("At", log_msg); - log_msg += ", Mean rms=" + std::to_string(error_rates_[ET_RMS]); - log_msg += "%, delta=" + std::to_string(error_rates_[ET_DELTA]); - log_msg += "%, BCER train=" + std::to_string(error_rates_[ET_CHAR_ERROR]); - log_msg += "%, BWER train=" + std::to_string(error_rates_[ET_WORD_RECERR]); - log_msg += "%, skip ratio=" + std::to_string(error_rates_[ET_SKIP_RATIO]); - log_msg += "%, "; + log_msg << std::fixed << std::setprecision(3) + << ", mean rms=" << error_rates_[ET_RMS] + << "%, delta=" << error_rates_[ET_DELTA] + << "%, BCER train=" << error_rates_[ET_CHAR_ERROR] + << "%, BWER train=" << error_rates_[ET_WORD_RECERR] + << "%, skip ratio=" << error_rates_[ET_SKIP_RATIO] << "%,"; } // Appends iteration learning_iteration()/training_iteration()/ // sample_iteration() to the log_msg. void LSTMTrainer::LogIterations(const char *intro_str, - std::string &log_msg) const { - log_msg += intro_str; - log_msg += " iteration " + std::to_string(learning_iteration()); - log_msg += "/" + std::to_string(training_iteration()); - log_msg += "/" + std::to_string(sample_iteration()); + std::stringstream &log_msg) const { + log_msg << intro_str + << " iteration " << learning_iteration() + << "/" << training_iteration() + << "/" << sample_iteration(); } // Returns true and increments the training_stage_ if the error rate has just @@ -602,14 +602,14 @@ bool LSTMTrainer::DeSerialize(const TessdataManager *mgr, TFile *fp) { // De-serializes the saved best_trainer_ into sub_trainer_, and adjusts the // learning rates (by scaling reduction, or layer specific, according to // NF_LAYER_SPECIFIC_LR). -void LSTMTrainer::StartSubtrainer(std::string &log_msg) { +void LSTMTrainer::StartSubtrainer(std::stringstream &log_msg) { sub_trainer_ = std::make_unique(); if (!ReadTrainingDump(best_trainer_, *sub_trainer_)) { - log_msg += " Failed to revert to previous best for trial!"; + log_msg << " Failed to revert to previous best for trial!"; sub_trainer_.reset(); } else { - log_msg += " Trial sub_trainer_ from iteration " + - std::to_string(sub_trainer_->training_iteration()); + log_msg << " Trial sub_trainer_ from iteration " + << sub_trainer_->training_iteration(); // Reduce learning rate so it doesn't diverge this time. sub_trainer_->ReduceLearningRates(this, log_msg); // If it fails again, we will wait twice as long before reverting again. @@ -630,14 +630,13 @@ void LSTMTrainer::StartSubtrainer(std::string &log_msg) { // trainer in *this is replaced with sub_trainer_, and STR_REPLACED is // returned. STR_NONE is returned if the subtrainer wasn't good enough to // receive any training iterations. -SubTrainerResult LSTMTrainer::UpdateSubtrainer(std::string &log_msg) { +SubTrainerResult LSTMTrainer::UpdateSubtrainer(std::stringstream &log_msg) { double training_error = CharError(); double sub_error = sub_trainer_->CharError(); double sub_margin = (training_error - sub_error) / sub_error; if (sub_margin >= kSubTrainerMarginFraction) { - log_msg += " sub_trainer=" + std::to_string(sub_error); - log_msg += " margin=" + std::to_string(100.0 * sub_margin); - log_msg += "\n"; + log_msg << " sub_trainer=" << sub_error + << " margin=" << 100.0 * sub_margin << "\n"; // Catch up to current iteration. int end_iteration = training_iteration(); while (sub_trainer_->training_iteration() < end_iteration && @@ -647,11 +646,12 @@ SubTrainerResult LSTMTrainer::UpdateSubtrainer(std::string &log_msg) { while (sub_trainer_->training_iteration() < target_iteration) { sub_trainer_->TrainOnLine(this, false); } - std::string batch_log = "Sub:"; + std::stringstream batch_log("Sub:"); + batch_log.imbue(std::locale::classic()); sub_trainer_->PrepareLogMsg(batch_log); - batch_log += "\n"; - tprintf("UpdateSubtrainer:%s", batch_log.c_str()); - log_msg += batch_log; + batch_log << "\n"; + tprintf("UpdateSubtrainer:%s", batch_log.str().c_str()); + log_msg << batch_log.str(); sub_error = sub_trainer_->CharError(); sub_margin = (training_error - sub_error) / sub_error; } @@ -661,9 +661,8 @@ SubTrainerResult LSTMTrainer::UpdateSubtrainer(std::string &log_msg) { std::vector updated_trainer; SaveTrainingDump(LIGHT, *sub_trainer_, &updated_trainer); ReadTrainingDump(updated_trainer, *this); - log_msg += " Sub trainer wins at iteration " + - std::to_string(training_iteration()); - log_msg += "\n"; + log_msg << " Sub trainer wins at iteration " + << training_iteration() << "\n"; return STR_REPLACED; } return STR_UPDATED; @@ -674,17 +673,16 @@ SubTrainerResult LSTMTrainer::UpdateSubtrainer(std::string &log_msg) { // Reduces network learning rates, either for everything, or for layers // independently, according to NF_LAYER_SPECIFIC_LR. void LSTMTrainer::ReduceLearningRates(LSTMTrainer *samples_trainer, - std::string &log_msg) { + std::stringstream &log_msg) { if (network_->TestFlag(NF_LAYER_SPECIFIC_LR)) { int num_reduced = ReduceLayerLearningRates( kLearningRateDecay, kNumAdjustmentIterations, samples_trainer); - log_msg += - "\nReduced learning rate on layers: " + std::to_string(num_reduced); + log_msg << "\nReduced learning rate on layers: " << num_reduced; } else { ScaleLearningRate(kLearningRateDecay); - log_msg += "\nReduced learning rate to :" + std::to_string(learning_rate_); + log_msg << "\nReduced learning rate to :" << learning_rate_; } - log_msg += "\n"; + log_msg << "\n"; } // Considers reducing the learning rate independently for each layer down by diff --git a/src/training/unicharset/lstmtrainer.h b/src/training/unicharset/lstmtrainer.h index 026e4b11..6481a59c 100644 --- a/src/training/unicharset/lstmtrainer.h +++ b/src/training/unicharset/lstmtrainer.h @@ -25,6 +25,7 @@ #include "rect.h" #include // for std::function +#include // for std::stringstream namespace tesseract { @@ -192,7 +193,7 @@ public: // Keeps track of best and locally worst error rate, using internally computed // values. See MaintainCheckpointsSpecific for more detail. - bool MaintainCheckpoints(const TestCallback &tester, std::string &log_msg); + bool MaintainCheckpoints(const TestCallback &tester, std::stringstream &log_msg); // Keeps track of best and locally worst error_rate (whatever it is) and // launches tests using rec_model, when a new min or max is reached. // Writes checkpoints using train_model at appropriate times and builds and @@ -201,12 +202,12 @@ public: bool MaintainCheckpointsSpecific(int iteration, const std::vector *train_model, const std::vector *rec_model, - TestCallback tester, std::string &log_msg); - // Builds a string containing a progress message with current error rates. - void PrepareLogMsg(std::string &log_msg) const; + TestCallback tester, std::stringstream &log_msg); + // Builds a progress message with current error rates. + void PrepareLogMsg(std::stringstream &log_msg) const; // Appends iteration learning_iteration()/training_iteration()/ // sample_iteration() to the log_msg. - void LogIterations(const char *intro_str, std::string &log_msg) const; + void LogIterations(const char *intro_str, std::stringstream &log_msg) const; // TODO(rays) Add curriculum learning. // Returns true and increments the training_stage_ if the error rate has just @@ -226,7 +227,7 @@ public: // De-serializes the saved best_trainer_ into sub_trainer_, and adjusts the // learning rates (by scaling reduction, or layer specific, according to // NF_LAYER_SPECIFIC_LR). - void StartSubtrainer(std::string &log_msg); + void StartSubtrainer(std::stringstream &log_msg); // While the sub_trainer_ is behind the current training iteration and its // training error is at least kSubTrainerMarginFraction better than the // current training error, trains the sub_trainer_, and returns STR_UPDATED if @@ -235,10 +236,10 @@ public: // trainer in *this is replaced with sub_trainer_, and STR_REPLACED is // returned. STR_NONE is returned if the subtrainer wasn't good enough to // receive any training iterations. - SubTrainerResult UpdateSubtrainer(std::string &log_msg); + SubTrainerResult UpdateSubtrainer(std::stringstream &log_msg); // Reduces network learning rates, either for everything, or for layers // independently, according to NF_LAYER_SPECIFIC_LR. - void ReduceLearningRates(LSTMTrainer *samples_trainer, std::string &log_msg); + void ReduceLearningRates(LSTMTrainer *samples_trainer, std::stringstream &log_msg); // Considers reducing the learning rate independently for each layer down by // factor(<1), or leaving it the same, by double-training the given number of // samples and minimizing the amount of changing of sign of weight updates. diff --git a/unittest/lstm_test.h b/unittest/lstm_test.h index 0b0ff6f5..d1de2eb7 100644 --- a/unittest/lstm_test.h +++ b/unittest/lstm_test.h @@ -103,7 +103,7 @@ protected: int iteration_limit = iteration + max_iterations; double best_error = 100.0; do { - std::string log_str; + std::stringstream log_str; int target_iteration = iteration + kBatchIterations; // Train a few. double mean_error = 0.0;