Added log levels (#414)

* Added log levels to line scan

* Fixed bold in readme

* Added flush on exit to ls

* Added plugin logging

* frame logging

* Added output to info logs

README.md

@@ -71,7 +71,26 @@ camera operations, as described in its
 Logging of the internal operations in the sensor models can be enabled by setting
 the `USGSCSM_LOG_FILE` environment variable to the file the log should be written to.
 To have the logging information printed to the standard output or standard error, set
-this to `stdout` or `stderr`. Note that these logs can become several GB in size.
+this to `stdout` or `stderr`.
+
+You can adjust how much information is logged by setting the `USGSCSM_LOG_LEVEL`
+environment variable. The log level is not case sensitive.
+The log levels are:
+
+| Level | Description |
+| ----- | ----------- |
+| trace | Intermediate calculation values |
+| debug | All function calls and returns |
+| **info** | Only core photogrammetry calls and returns - Default log level |
+| warn | CSM warnings |
+| err | CSM exceptions |
+| critical | Critical errors |
+| off | No log messages |
+
+All log messages of level `USGSCSM_LOG_LEVEL` and below will be logged. For example,
+setting the log level to *info* will log all messages of types *info*, *warn*, *err*,
+*critical*, and *off*. Note that these logs can become several GB in size when the
+log level is set to *debug* or *trace*.
 
 ---
 

src/UsgsAstroPlugin.cpp

@@ -55,7 +55,7 @@ using json = nlohmann::json;
 
 #define MESSAGE_LOG(...)         \
   if (m_logger) {                \
-    m_logger->info(__VA_ARGS__); \
+    m_logger->log(__VA_ARGS__); \
   }
 
 // Declaration of static variables
@@ -75,21 +75,27 @@ UsgsAstroPlugin::UsgsAstroPlugin() {
     std::string logFile(logFilePtr);
 
     if (logFile != "") {
-      std::shared_ptr<spdlog::logger> m_logger = spdlog::get("usgscsm_logger");
+      m_logger = spdlog::get("usgscsm_logger");
 
       if (!m_logger) {
         if (logFile == "stdout") {
-          std::shared_ptr<spdlog::logger> m_logger =
-              spdlog::stdout_color_mt("usgscsm_logger");
+          m_logger = spdlog::stdout_color_mt("usgscsm_logger");
         }
         else if (logFile == "stderr") {
-          std::shared_ptr<spdlog::logger> m_logger =
-              spdlog::stderr_color_mt("usgscsm_logger");
+          m_logger = spdlog::stderr_color_mt("usgscsm_logger");
         }
         else {
-          std::shared_ptr<spdlog::logger> m_logger =
-              spdlog::basic_logger_mt("usgscsm_logger", logFile);
+          m_logger = spdlog::basic_logger_mt("usgscsm_logger", logFile);
         }
+
+        char *logLevlPtr = getenv("USGSCSM_LOG_LEVEL");
+        if (logLevlPtr != NULL) {
+          std::string logLevelStr(logLevlPtr);
+          std::transform(logLevelStr.begin(), logLevelStr.end(), logLevelStr.begin(),
+              [](unsigned char c){ return std::tolower(c); });
+          m_logger->set_level(spdlog::level::from_str(logLevelStr));
+        }
+
       }
     }
   }
@@ -98,27 +104,27 @@ UsgsAstroPlugin::UsgsAstroPlugin() {
 UsgsAstroPlugin::~UsgsAstroPlugin() {}
 
 std::string UsgsAstroPlugin::getPluginName() const {
-  MESSAGE_LOG("Get Plugin Name: {}", _PLUGIN_NAME);
+  MESSAGE_LOG(spdlog::level::debug, "Get Plugin Name: {}", _PLUGIN_NAME);
   return _PLUGIN_NAME;
 }
 
 std::string UsgsAstroPlugin::getManufacturer() const {
-  MESSAGE_LOG("Get Manufacturer Name: {}", _MANUFACTURER_NAME);
+  MESSAGE_LOG(spdlog::level::debug, "Get Manufacturer Name: {}", _MANUFACTURER_NAME);
   return _MANUFACTURER_NAME;
 }
 
 std::string UsgsAstroPlugin::getReleaseDate() const {
-  MESSAGE_LOG("Get Release Date: {}", _RELEASE_DATE);
+  MESSAGE_LOG(spdlog::level::debug, "Get Release Date: {}", _RELEASE_DATE);
   return _RELEASE_DATE;
 }
 
 csm::Version UsgsAstroPlugin::getCsmVersion() const {
-  MESSAGE_LOG("Get Current CSM Version");
+  MESSAGE_LOG(spdlog::level::debug, "Get Current CSM Version");
   return CURRENT_CSM_VERSION;
 }
 
 size_t UsgsAstroPlugin::getNumModels() const {
-  MESSAGE_LOG("Get Number of Sensor Models: {}", _N_SENSOR_MODELS);
+  MESSAGE_LOG(spdlog::level::debug, "Get Number of Sensor Models: {}", _N_SENSOR_MODELS);
   return _N_SENSOR_MODELS;
 }
 
@@ -128,19 +134,19 @@ std::string UsgsAstroPlugin::getModelName(size_t modelIndex) const {
       UsgsAstroLsSensorModel::_SENSOR_MODEL_NAME,
       UsgsAstroSarSensorModel::_SENSOR_MODEL_NAME,
       UsgsAstroPushFrameSensorModel::_SENSOR_MODEL_NAME};
-  MESSAGE_LOG("Get Model Name: {}. Used index: {}",
+  MESSAGE_LOG(spdlog::level::debug, "Get Model Name: {}. Used index: {}",
               supportedModelNames[modelIndex], modelIndex);
   return supportedModelNames[modelIndex];
 }
 
 std::string UsgsAstroPlugin::getModelFamily(size_t modelIndex) const {
-  MESSAGE_LOG("Get Model Familey: {}", CSM_RASTER_FAMILY);
+  MESSAGE_LOG(spdlog::level::debug, "Get Model Familey: {}", CSM_RASTER_FAMILY);
   return CSM_RASTER_FAMILY;
 }
 
 csm::Version UsgsAstroPlugin::getModelVersion(
     const std::string &modelName) const {
-  MESSAGE_LOG("Get Model Version");
+  MESSAGE_LOG(spdlog::level::debug, "Get Model Version");
   return csm::Version(1, 0, 0);
 }
 
@@ -175,7 +181,7 @@ bool UsgsAstroPlugin::canModelBeConstructedFromState(
   fullMsg += err_msg;
   fullMsg += "]";
 
-  MESSAGE_LOG(fullMsg);
+  MESSAGE_LOG(spdlog::level::err, fullMsg);
   if (warnings) {
     warnings->push_back(csm::Warning
                         (csm::Warning::UNKNOWN_WARNING, fullMsg,
@@ -200,7 +206,7 @@ bool UsgsAstroPlugin::canModelBeConstructedFromISD(
       msg += "] with error [";
       msg += e.what();
       msg += "]";
-      MESSAGE_LOG(msg);
+      MESSAGE_LOG(spdlog::level::warn, msg);
       warnings->push_back(csm::Warning(
           csm::Warning::UNKNOWN_WARNING, msg,
           "UsgsAstroFrameSensorModel::canModelBeConstructedFromISD()"));
@@ -210,7 +216,7 @@ bool UsgsAstroPlugin::canModelBeConstructedFromISD(
       std::string msg = "Could not create model [";
       msg += modelName;
       msg += "] with an unknown error.";
-      MESSAGE_LOG(msg);
+      MESSAGE_LOG(spdlog::level::warn, msg);
       warnings->push_back(csm::Warning(
           csm::Warning::UNKNOWN_WARNING, msg,
           "UsgsAstroFrameSensorModel::canModelBeConstructedFromISD()"));
@@ -231,7 +237,7 @@ std::string UsgsAstroPlugin::loadImageSupportData(
   lastIndex = baseName.find_last_of(DIR_DELIMITER_STR);
   std::string filename = baseName.substr(lastIndex + 1);
   std::string isdFilename = baseName.append(".json");
-  MESSAGE_LOG("Load Image Support Data using: {}, {}, {}, {}, {}",
+  MESSAGE_LOG(spdlog::level::info, "Load Image Support Data using: {}, {}, {}, {}, {}",
               imageFilename, lastIndex, baseName, filename, isdFilename);
   try {
     std::ifstream isd_sidecar(isdFilename);
@@ -246,7 +252,7 @@ std::string UsgsAstroPlugin::loadImageSupportData(
     errorMessage += "] with error [";
     errorMessage += e.what();
     errorMessage += "]";
-    MESSAGE_LOG(errorMessage);
+    MESSAGE_LOG(spdlog::level::err, errorMessage);
     throw csm::Error(csm::Error::FILE_READ, errorMessage,
                      "UsgsAstroPlugin::loadImageSupportData");
   }
@@ -257,13 +263,13 @@ std::string UsgsAstroPlugin::getModelNameFromModelState(
   auto state = stateAsJson(modelState);
 
   std::string name = state.value<std::string>("name_model", "");
-  MESSAGE_LOG("Get model name from model state. State: {}, Name: {}",
+  MESSAGE_LOG(spdlog::level::debug, "Get model name from model state. State: {}, Name: {}",
               modelState, name);
   if (name == "") {
     csm::Error::ErrorType aErrorType = csm::Error::INVALID_SENSOR_MODEL_STATE;
     std::string aMessage = "No 'name_model' key in the model state object.";
     std::string aFunction = "UsgsAstroPlugin::getModelNameFromModelState";
-    MESSAGE_LOG(aMessage);
+    MESSAGE_LOG(spdlog::level::err, aMessage);
     csm::Error csmErr(aErrorType, aMessage, aFunction);
     throw(csmErr);
   }
@@ -274,7 +280,7 @@ std::string UsgsAstroPlugin::getModelNameFromModelState(
 bool UsgsAstroPlugin::canISDBeConvertedToModelState(
     const csm::Isd &imageSupportData, const std::string &modelName,
     csm::WarningList *warnings) const {
-  MESSAGE_LOG("Running canISDBeConvertedToModelState");
+  MESSAGE_LOG(spdlog::level::debug, "Running canISDBeConvertedToModelState");
   try {
     convertISDToModelState(imageSupportData, modelName, warnings);
   } catch (std::exception &e) {
@@ -284,7 +290,7 @@ bool UsgsAstroPlugin::canISDBeConvertedToModelState(
       msg += "] state with error [";
       msg += e.what();
       msg += "]";
-      MESSAGE_LOG(msg);
+      MESSAGE_LOG(spdlog::level::warn, msg);
       warnings->push_back(csm::Warning(
           csm::Warning::UNKNOWN_WARNING, msg,
           "UsgsAstroFrameSensorModel::canISDBeConvertedToModelState()"));
@@ -295,9 +301,9 @@ bool UsgsAstroPlugin::canISDBeConvertedToModelState(
 }
 
 std::string UsgsAstroPlugin::getStateFromISD(csm::Isd imageSupportData) const {
-  MESSAGE_LOG("Running getStateFromISD");
+  MESSAGE_LOG(spdlog::level::debug, "Running getStateFromISD");
   std::string stringIsd = loadImageSupportData(imageSupportData);
-  MESSAGE_LOG("ISD string: {}", stringIsd);
+  MESSAGE_LOG(spdlog::level::trace, "ISD string: {}", stringIsd);
   json jsonIsd = json::parse(stringIsd);
   return convertISDToModelState(imageSupportData, jsonIsd.at("name_model"));
 }
@@ -305,7 +311,7 @@ std::string UsgsAstroPlugin::getStateFromISD(csm::Isd imageSupportData) const {
 std::string UsgsAstroPlugin::convertISDToModelState(
     const csm::Isd &imageSupportData, const std::string &modelName,
     csm::WarningList *warnings) const {
-  MESSAGE_LOG("Running convertISDToModelState");
+  MESSAGE_LOG(spdlog::level::info, "Running convertISDToModelState");
   std::shared_ptr<csm::Model> sensor_model
     (constructModelFromISD(imageSupportData, modelName, warnings));
   std::string stateString = sensor_model->getModelState();
@@ -315,17 +321,17 @@ std::string UsgsAstroPlugin::convertISDToModelState(
 csm::Model *UsgsAstroPlugin::constructModelFromISD(
     const csm::Isd &imageSupportDataOriginal, const std::string &modelName,
     csm::WarningList *warnings) const {
-  MESSAGE_LOG("Running constructModelFromISD");
+  MESSAGE_LOG(spdlog::level::info, "Running constructModelFromISD");
   std::string stringIsd = loadImageSupportData(imageSupportDataOriginal);
 
-  MESSAGE_LOG("ISD String: {}", stringIsd);
+  MESSAGE_LOG(spdlog::level::trace, "ISD String: {}", stringIsd);
   if (modelName == UsgsAstroFrameSensorModel::_SENSOR_MODEL_NAME) {
     UsgsAstroFrameSensorModel *model = new UsgsAstroFrameSensorModel();
     try {
-      MESSAGE_LOG("Trying to construct a UsgsAstroFrameSensorModel");
+      MESSAGE_LOG(spdlog::level::debug, "Trying to construct a UsgsAstroFrameSensorModel");
       model->replaceModelState(
           model->constructStateFromIsd(stringIsd, warnings));
-      MESSAGE_LOG("Constructed model: {}", modelName);
+      MESSAGE_LOG(spdlog::level::debug, "Constructed model: {}", modelName);
     } catch (std::exception &e) {
       delete model;
       csm::Error::ErrorType aErrorType =
@@ -335,7 +341,7 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
       aMessage += "] with error [";
       aMessage += e.what();
       aMessage += "]";
-      MESSAGE_LOG(aMessage);
+      MESSAGE_LOG(spdlog::level::err, aMessage);
       std::string aFunction = "UsgsAstroPlugin::constructModelFromISD()";
       throw csm::Error(aErrorType, aMessage, aFunction);
     }
@@ -343,7 +349,7 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
   } else if (modelName == UsgsAstroLsSensorModel::_SENSOR_MODEL_NAME) {
     UsgsAstroLsSensorModel *model = new UsgsAstroLsSensorModel();
     try {
-      MESSAGE_LOG("Trying to construct a UsgsAstroLsSensorModel");
+      MESSAGE_LOG(spdlog::level::debug, "Trying to construct a UsgsAstroLsSensorModel");
       model->replaceModelState(
           model->constructStateFromIsd(stringIsd, warnings));
     } catch (std::exception &e) {
@@ -356,13 +362,13 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
       aMessage += e.what();
       aMessage += "]";
       std::string aFunction = "UsgsAstroPlugin::constructModelFromISD()";
-      MESSAGE_LOG(aMessage);
+      MESSAGE_LOG(spdlog::level::err, aMessage);
       throw csm::Error(aErrorType, aMessage, aFunction);
     }
     return model;
   } else if (modelName == UsgsAstroSarSensorModel::_SENSOR_MODEL_NAME) {
     UsgsAstroSarSensorModel *model = new UsgsAstroSarSensorModel();
-    MESSAGE_LOG("Trying to construct a UsgsAstroSarSensorModel");
+    MESSAGE_LOG(spdlog::level::debug, "Trying to construct a UsgsAstroSarSensorModel");
     try {
       model->replaceModelState(
           model->constructStateFromIsd(stringIsd, warnings));
@@ -376,13 +382,13 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
       aMessage += e.what();
       aMessage += "]";
       std::string aFunction = "UsgsAstroPlugin::constructModelFromISD()";
-      MESSAGE_LOG(aMessage);
+      MESSAGE_LOG(spdlog::level::err, aMessage);
       throw csm::Error(aErrorType, aMessage, aFunction);
     }
     return model;
   } else if (modelName == UsgsAstroPushFrameSensorModel::_SENSOR_MODEL_NAME) {
     UsgsAstroPushFrameSensorModel *model = new UsgsAstroPushFrameSensorModel();
-    MESSAGE_LOG("Trying to construct a UsgsAstroPushFrameSensorModel");
+    MESSAGE_LOG(spdlog::level::debug, "Trying to construct a UsgsAstroPushFrameSensorModel");
     try {
       model->replaceModelState(
           model->constructStateFromIsd(stringIsd, warnings));
@@ -396,7 +402,7 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
       aMessage += e.what();
       aMessage += "]";
       std::string aFunction = "UsgsAstroPlugin::constructModelFromISD()";
-      MESSAGE_LOG(aMessage);
+      MESSAGE_LOG(spdlog::level::err, aMessage);
       throw csm::Error(aErrorType, aMessage, aFunction);
     }
     return model;
@@ -404,30 +410,30 @@ csm::Model *UsgsAstroPlugin::constructModelFromISD(
     csm::Error::ErrorType aErrorType = csm::Error::SENSOR_MODEL_NOT_SUPPORTED;
     std::string aMessage = "Model [" + modelName + "] not supported: ";
     std::string aFunction = "UsgsAstroPlugin::constructModelFromISD()";
-    MESSAGE_LOG(aMessage);
+    MESSAGE_LOG(spdlog::level::err, aMessage);
     throw csm::Error(aErrorType, aMessage, aFunction);
   }
 }
 
 csm::Model *UsgsAstroPlugin::constructModelFromState(
     const std::string &modelState, csm::WarningList *warnings) const {
-  MESSAGE_LOG("Runing constructModelFromState with modelState: {}", modelState);
+  MESSAGE_LOG(spdlog::level::info, "Runing constructModelFromState with modelState: {}", modelState);
   json state = stateAsJson(modelState);
   std::string modelName = state["m_modelName"];
-  MESSAGE_LOG("Using model name: {}", modelName);
+  MESSAGE_LOG(spdlog::level::debug, "Using model name: {}", modelName);
 
   if (modelName == UsgsAstroFrameSensorModel::_SENSOR_MODEL_NAME) {
-    MESSAGE_LOG("Constructing a UsgsAstroFrameSensorModel");
+    MESSAGE_LOG(spdlog::level::debug, "Constructing a UsgsAstroFrameSensorModel");
     UsgsAstroFrameSensorModel *model = new UsgsAstroFrameSensorModel();
     model->replaceModelState(modelState);
     return model;
   } else if (modelName == UsgsAstroLsSensorModel::_SENSOR_MODEL_NAME) {
-    MESSAGE_LOG("Constructing a UsgsAstroLsSensorModel");
+    MESSAGE_LOG(spdlog::level::debug, "Constructing a UsgsAstroLsSensorModel");
     UsgsAstroLsSensorModel *model = new UsgsAstroLsSensorModel();
     model->replaceModelState(modelState);
     return model;
   } else if (modelName == UsgsAstroSarSensorModel::_SENSOR_MODEL_NAME) {
-    MESSAGE_LOG("Constructing a UsgsAstroSarSensorModel");
+    MESSAGE_LOG(spdlog::level::debug, "Constructing a UsgsAstroSarSensorModel");
     UsgsAstroSarSensorModel *model = new UsgsAstroSarSensorModel();
     model->replaceModelState(modelState);
     return model;
@@ -435,7 +441,7 @@ csm::Model *UsgsAstroPlugin::constructModelFromState(
     csm::Error::ErrorType aErrorType = csm::Error::ISD_NOT_SUPPORTED;
     std::string aMessage = "Model" + modelName + " not supported: ";
     std::string aFunction = "UsgsAstroPlugin::constructModelFromState()";
-    MESSAGE_LOG(aMessage);
+    MESSAGE_LOG(spdlog::level::err, aMessage);
     throw csm::Error(aErrorType, aMessage, aFunction);
   }
 }

tests/Fixtures.h

@@ -87,6 +87,7 @@ class FrameSensorModelLogging : public ::testing::Test {
     std::uintptr_t sensorId = reinterpret_cast<std::uintptr_t>(sensorModel);
     auto logger = std::make_shared<spdlog::logger>(std::to_string(sensorId),
                                                    ostream_sink);
+    logger->set_level(spdlog::level::trace);
     spdlog::register_logger(logger);
 
     sensorModel->setLogger(std::to_string(sensorId));