From d1bbe8538ed972dc69a0ca8fa73bb997ca584650 Mon Sep 17 00:00:00 2001
From: Daniel Wolf <dwolf@dannad.de>
Date: Tue, 14 Jun 2016 17:38:11 +0200
Subject: [PATCH] Added more logging

---
 CMakeLists.txt                       |  2 ++
 src/audio/voiceActivityDetection.cpp |  6 ++++++
 src/g2p.cpp                          |  9 ++++++++-
 src/main.cpp                         | 12 +++++++++++-
 src/phoneExtraction.cpp              |  2 ++
 5 files changed, 29 insertions(+), 2 deletions(-)

diff --git a/CMakeLists.txt b/CMakeLists.txt
index d072222..2cb7c31 100644
--- a/CMakeLists.txt
+++ b/CMakeLists.txt
@@ -217,6 +217,8 @@ set(TEST_FILES
 	src/Phone.cpp src/Phone.h
 	src/tokenization.cpp src/tokenization.h
 	src/g2p.cpp src/g2p.h
+	src/logging.cpp src/logging.h
+	src/tools.cpp src/tools.h
 )
 add_executable(runTests ${TEST_FILES})
 target_link_libraries(runTests gtest gmock gmock_main flite cppFormat)
diff --git a/src/audio/voiceActivityDetection.cpp b/src/audio/voiceActivityDetection.cpp
index 9519985..efe8173 100644
--- a/src/audio/voiceActivityDetection.cpp
+++ b/src/audio/voiceActivityDetection.cpp
@@ -4,10 +4,13 @@
 #include <boost/optional/optional.hpp>
 #include <logging.h>
 #include <pairs.h>
+#include <boost/range/adaptor/transformed.hpp>
 
 using std::numeric_limits;
 using std::vector;
 using boost::optional;
+using boost::adaptors::transformed;
+using fmt::format;
 
 float getRMS(AudioStream& audioStream, int maxSampleCount = numeric_limits<int>::max()) {
 	double sum = 0;
@@ -53,5 +56,8 @@ BoundedTimeline<void> detectVoiceActivity(std::unique_ptr<AudioStream> audioStre
 		}
 	}
 
+	logging::debugFormat("Found {} sections of voice activity: {}", activity.size(),
+		join(activity | transformed([](const Timed<void>& t) { return format("{0}-{1}", t.getStart(), t.getEnd()); }), ", "));
+
 	return activity;
 }
diff --git a/src/g2p.cpp b/src/g2p.cpp
index f96f03c..424f6da 100644
--- a/src/g2p.cpp
+++ b/src/g2p.cpp
@@ -1,6 +1,7 @@
 #include <g2p.h>
 #include <regex>
 #include "stringTools.h"
+#include "logging.h"
 
 using std::vector;
 using std::wstring;
@@ -89,7 +90,13 @@ vector<Phone> wordToPhones(const std::string& word) {
 
 	vector<Phone> result;
 	for (wchar_t c : wideWord) {
-		result.push_back(charToPhone(c));
+		Phone phone = charToPhone(c);
+		if (phone == Phone::Unknown) {
+			logging::errorFormat("G2P error determining pronunciation for '{}': Character '{}' is not a recognized phone shorthand.",
+				word, static_cast<char>(c));
+		} else {
+			result.push_back(phone);
+		}
 	}
 	return result;
 }
diff --git a/src/main.cpp b/src/main.cpp
index 131cbdf..4a6c3a8 100644
--- a/src/main.cpp
+++ b/src/main.cpp
@@ -14,6 +14,7 @@
 #include "ContinuousTimeline.h"
 #include <boost/filesystem/operations.hpp>
 #include "stringTools.h"
+#include <boost/range/adaptor/transformed.hpp>
 
 using std::exception;
 using std::string;
@@ -27,6 +28,7 @@ using std::map;
 using std::chrono::duration;
 using std::chrono::duration_cast;
 using boost::filesystem::path;
+using boost::adaptors::transformed;
 
 namespace tclap = TCLAP;
 
@@ -131,6 +133,9 @@ int main(int argc, char *argv[]) {
 			addFileSink(path(logFileName.getValue()), logLevel.getValue());
 		}
 
+		logging::infoFormat("Application startup. Command line: {}", join(
+			vector<char*>(argv, argv + argc) | transformed([](char* arg) { return fmt::format("\"{}\"", arg); }), " "));
+
 		// Detect phones
 		const int columnWidth = 30;
 		std::cerr << std::left;
@@ -168,20 +173,25 @@ int main(int argc, char *argv[]) {
 			throw std::runtime_error("Unknown export format.");
 		}
 		exporter->exportShapes(path(inputFileName.getValue()), shapes, std::cout);
+		logging::info("Exiting application normally.");
 
 		return 0;
 	} catch (tclap::ArgException& e) {
 		// Error parsing command-line args.
 		cmd.getOutput()->failure(cmd, e);
 		std::cerr << std::endl;
+		logging::error("Invalid command line. Exiting application with error code.");
 		return 1;
 	} catch (tclap::ExitException&) {
 		// A built-in TCLAP command (like --help) has finished. Exit application.
 		std::cerr << std::endl;
+		logging::info("Exiting application after help-like command.");
 		return 0;
 	} catch (const exception& e) {
 		// Generic error
-		std::cerr << "An error occurred.\n" << getMessage(e) << std::endl;
+		string message = getMessage(e);
+		std::cerr << "An error occurred.\n" << message << std::endl;
+		logging::errorFormat("Exiting application with error: {}", message);
 		return 1;
 	}
 }
diff --git a/src/phoneExtraction.cpp b/src/phoneExtraction.cpp
index 8201899..91b56d6 100644
--- a/src/phoneExtraction.cpp
+++ b/src/phoneExtraction.cpp
@@ -334,6 +334,7 @@ BoundedTimeline<Phone> detectPhones(
 		ps_set_search(decoder.get(), "lm");
 
 		BoundedTimeline<Phone> result(audioStream->getTruncatedRange());
+		logging::debug("Speech recognition -- start");
 		for (const auto& timedUtterance : utterances) {
 			ProgressMerger utteranceProgressMerger(**utteranceProgressSinkIt++);
 			ProgressSink& wordRecognitionProgressSink = utteranceProgressMerger.addSink(1.0);
@@ -370,6 +371,7 @@ BoundedTimeline<Phone> detectPhones(
 				result.set(timedPhone);
 			}
 		}
+		logging::debug("Speech recognition -- end");
 
 		return result;
 	}