Merge release candidate to development

extern/test_bmi_c/src/bmi_test_bmi_c.c

@@ -21,7 +21,7 @@ static const char *output_var_locations[OUTPUT_VAR_NAME_COUNT] = { "node", "node
 // Don't forget to update Get_value/Get_value_at_indices (and setter) implementation if these are adjusted
 static const char *input_var_names[INPUT_VAR_NAME_COUNT] = { "INPUT_VAR_1", "INPUT_VAR_2" };
 static const char *input_var_types[INPUT_VAR_NAME_COUNT] = { "double", "double" };
-static const char *input_var_units[INPUT_VAR_NAME_COUNT] = {  "m", "m/s" };
+static const char *input_var_units[INPUT_VAR_NAME_COUNT] = {  "m", "Pa" };
 static const int input_var_item_count[INPUT_VAR_NAME_COUNT] = { 1, 1 };
 static const char *input_var_grids[INPUT_VAR_NAME_COUNT] = { 0, 0 };
 static const char *input_var_locations[INPUT_VAR_NAME_COUNT] = { "node", "node" };

extern/test_bmi_cpp/include/test_bmi_cpp.hpp

@@ -172,8 +172,8 @@ class TestBmiCpp : public bmi::Bmi {
         std::vector<std::string> input_var_types = { "double", "double" };
         std::vector<std::string> output_var_types = { "double", "double" };
         std::vector<std::string> model_var_types = {};
-        std::vector<std::string> input_var_units = { "m", "m" };
-        std::vector<std::string> output_var_units = { "m", "m/s", "m", "m" };
+        std::vector<std::string> input_var_units = { "mm/s", "Pa" };
+        std::vector<std::string> output_var_units = { "mm/s", "m/s", "m", "m" };
         std::vector<std::string> model_var_units = {};
         std::vector<std::string> input_var_locations = { "node", "node" };
         std::vector<std::string> output_var_locations = { "node", "node" };

extern/test_bmi_fortran/src/bmi_test_bmi_fortran.f90

@@ -123,10 +123,10 @@ module bmitestbmi
   integer :: input_grid(4) = [0, 0, 0, 1]
 
   character (len=BMI_MAX_UNITS_NAME) :: &
-    output_units(6) = [character(BMI_MAX_UNITS_NAME):: 'm', 'm', 's', 'm', 'm', 'm']
+    output_units(6) = [character(BMI_MAX_UNITS_NAME):: 'mm s^-1', 'm', 's', 'm', 'm', 'm']
 
   character (len=BMI_MAX_UNITS_NAME) :: &
-    input_units(4) = [character(BMI_MAX_UNITS_NAME):: 'm', 'm', 's', 'm']
+    input_units(4) = [character(BMI_MAX_UNITS_NAME):: 'mm s^-1', 'Pa', 'K', 'mm s^-1']
 
   character (len=BMI_MAX_LOCATION_NAME) :: &
     output_location(6) = [character(BMI_MAX_LOCATION_NAME):: 'node', 'node', 'node', 'node', 'node', 'node']

extern/test_bmi_py/bmi_model.py

@@ -73,12 +73,12 @@ def __init__(self):
     #     since the input variable names could come from any forcing...
     #------------------------------------------------------
     #_var_name_map_long_first = {
-    _var_name_units_map = {'INPUT_VAR_1':['INPUT_VAR_1','-'],
-                           'INPUT_VAR_2':['INPUT_VAR_2','-'],
-                           'OUTPUT_VAR_1':['OUTPUT_VAR_1','-'],
-                           'OUTPUT_VAR_2':['OUTPUT_VAR_2','-'],
+    _var_name_units_map = {'INPUT_VAR_1':['INPUT_VAR_1','mm/s'],
+                           'INPUT_VAR_2':['INPUT_VAR_2','Pa'],
+                           'OUTPUT_VAR_1':['OUTPUT_VAR_1','m'],
+                           'OUTPUT_VAR_2':['OUTPUT_VAR_2','mm/s'],
                            'OUTPUT_VAR_3':['OUTPUT_VAR_3','-'],
-                           'GRID_VAR_1':['OUTPUT_VAR_1','-'],
+                           'GRID_VAR_1':['OUTPUT_VAR_1','mm/s'],
                            'GRID_VAR_2':['GRID_VAR_2','-'],
                             }
 
@@ -609,4 +609,4 @@ def _parse_config(self, cfg):
                 pass
 
         # Add more config parsing if necessary
-        return cfg
+        return cfg

include/forcing/CsvPerFeatureForcingProvider.hpp

@@ -170,13 +170,13 @@ class CsvPerFeatureForcingProvider : public data_access::GenericDataProvider
         try {
             return UnitsHelper::get_converted_value(available_forcings_units[output_name], value, output_units);
         }
-        catch (const std::runtime_error& e){
-            #ifndef UDUNITS_QUIET
-            std::stringstream ss;
-            ss <<"WARN: Unit conversion unsuccessful - Returning unconverted value! (\""<<e.what()<<"\")"<<std::endl;
-            LOG(ss.str(), LogLevel::SEVERE); ss.str("");
-            #endif
-            return value;
+        catch (const std::runtime_error& e) {
+            data_access::unit_conversion_exception uce(e.what());
+            uce.provider_model_name = "CsvPerFeatureProvider " + std::to_string(catchment_id);
+            uce.provider_bmi_var_name = output_name;
+            uce.provider_units = available_forcings_units[output_name];
+            uce.unconverted_values.push_back(value);
+            throw uce;
         }
     }
 
@@ -341,12 +341,16 @@ class CsvPerFeatureForcingProvider : public data_access::GenericDataProvider
                     }
                 }
 
+                LOG("CsvProvider has variable '" + var_name + "' with units '" + units + "'", LogLevel::DEBUG);
+
                 auto wkf = data_access::WellKnownFields.find(var_name);
                 if(wkf != data_access::WellKnownFields.end()){
                     units = units.empty() ? std::get<1>(wkf->second) : units;
+                    auto wkf_name = std::get<0>(wkf->second);
+                    LOG("CsvProvider has well-known name '" + wkf_name + "' for variable '" + var_name + "' with units '" + units + "'", LogLevel::DEBUG);
                     available_forcings.push_back(var_name); // Allow lookup by non-canonical name
                     available_forcings_units[var_name] = units; // Allow lookup of units by non-canonical name
-                    var_name = std::get<0>(wkf->second); // Use the CSDMS name from here on
+                    var_name = wkf_name; // Use the CSDMS name from here on
                 }
 
                 forcing_vectors[var_name] = {};

include/forcing/DataProvider.hpp

@@ -3,6 +3,8 @@
 
 #include <string>
 #include <vector>
+#include <set>
+#include <tuple>
 #include <boost/core/span.hpp>
 
 namespace data_access
@@ -101,6 +103,33 @@ namespace data_access
         private:
     };
 
+    struct unit_error_log_key {
+        std::string requester_name;
+        std::string requester_variable;
+        std::string provider_name;
+        std::string provider_variable;
+        std::string failure_message;
+
+        bool operator<(unit_error_log_key const& rhs) const {
+            return std::tie(requester_name, requester_variable, provider_name, provider_variable, failure_message)
+                 < std::tie(rhs.requester_name, rhs.requester_variable, rhs.provider_name, rhs.provider_variable, rhs.failure_message);
+        }
+
+        bool operator==(unit_error_log_key const& rhs) const {
+            return std::tie(requester_name, requester_variable, provider_name, provider_variable, failure_message)
+                == std::tie(rhs.requester_name, rhs.requester_variable, rhs.provider_name, rhs.provider_variable, rhs.failure_message);
+        }
+    };
+
+    extern std::set<unit_error_log_key> unit_errors_reported;
+
+    struct unit_conversion_exception : public std::runtime_error {
+        unit_conversion_exception(std::string message) : std::runtime_error(message) {}
+        std::string provider_model_name;
+        std::string provider_bmi_var_name;
+        std::string provider_units;
+        std::vector<double> unconverted_values;
+    };
 }
 
 

include/forcing/ForcingsEngineDataProvider.hpp

@@ -16,6 +16,7 @@
 
 #include "DataProvider.hpp"
 #include "bmi/Bmi_Py_Adapter.hpp"
+#include "Logger.hpp"
 
 namespace data_access {
 
@@ -173,31 +174,38 @@ struct ForcingsEngineDataProvider : public DataProvider<DataType, SelectionType>
       : time_begin_(std::chrono::system_clock::from_time_t(time_begin_seconds))
       , time_end_(std::chrono::system_clock::from_time_t(time_end_seconds))
     {
+        std::stringstream ss; 
+
         // Log the constructor arguments
-        std::cout << "[ngen debug] Entering ForcingsEngineDataProvider constructor" << std::endl;
+        ss.str("");
+        ss << "Entering ForcingsEngineDataProvider constructor" << std::endl;
+        LOG(LogLevel::DEBUG, ss.str());
 
         std::time_t start_t = static_cast<std::time_t>(time_begin_seconds);
         std::time_t end_t   = static_cast<std::time_t>(time_end_seconds);
 
-        std::cout << "  Start time: " << std::put_time(std::gmtime(&start_t), "%Y-%m-%d %H:%M:%S UTC")
-                  << " (" << time_begin_seconds << ")" << std::endl;
+        ss.str("");
+        ss << "  Start time: " << std::put_time(std::gmtime(&start_t), "%Y-%m-%d %H:%M:%S UTC")
+           << " (" << time_begin_seconds << ")" << std::endl;
+        LOG(LogLevel::INFO, ss.str());
 
-        std::cout << "  End time:   " << std::put_time(std::gmtime(&end_t), "%Y-%m-%d %H:%M:%S UTC")
-                  << " (" << time_end_seconds << ")" << std::endl;
+        ss.str("");
+        ss << "  End time:   " << std::put_time(std::gmtime(&end_t), "%Y-%m-%d %H:%M:%S UTC")
+           << " (" << time_end_seconds << ")" << std::endl;
+        LOG(LogLevel::INFO, ss.str());
 
         // Attempt to retrieve a previously created BMI instance
         bmi_ = storage_type::instances.get(init_config);
 
         // If it doesn't exist, create it and assign it to the storage map
         if (bmi_ != nullptr) {
-            std::cout << "[ngen debug] Reusing existing BMI instance for init_config file: " << init_config << std::endl;
+            ss.str("");
+            ss << "Reusing existing BMI instance for init_config file: " << init_config << std::endl;
+            LOG(LogLevel::DEBUG, ss.str());
         } else {
-            // Ensure all prior output is flushed before invoking Python
-            std::cout.flush();
-            std::cerr.flush();
-
             // Log the creation of a new BMI instance
-            std::cout << "[ngen debug] Creating new BMI instance for init_config file: " << init_config << std::endl;
+            ss.str(""); ss << "Creating new BMI instance for init_config file: " << init_config << std::endl;
+            LOG(LogLevel::DEBUG, ss.str());
 
             // Create the BMI instance
             try {
@@ -208,7 +216,8 @@ struct ForcingsEngineDataProvider : public DataProvider<DataType, SelectionType>
                     /*has_fixed_time_step=*/true
                 );
             } catch (const std::exception& ex) {
-                std::cerr << "[ngen error] Failed to create Bmi_Py_Adapter: " << ex.what() << std::endl;
+                ss.str("");ss << "Failed to create Bmi_Py_Adapter: " << ex.what() << std::endl;
+                LOG(LogLevel::FATAL, ss.str());
                 throw;
             }
 
@@ -221,19 +230,28 @@ struct ForcingsEngineDataProvider : public DataProvider<DataType, SelectionType>
             // NOTE: using std::lround instead of static_cast will prevent potential UB
             time_step_ = std::chrono::seconds{std::lround(bmi_->GetTimeStep())};
             var_output_names_ = bmi_->GetOutputVarNames();
-            std::cout << "[ngen debug] BMI instance initialized successfully" << std::endl;
-            std::cout << "[ngen debug] Time step: " << time_step_.count() << " seconds" << std::endl;
-            std::cout << "[ngen debug] Available output variable names:" << std::endl;
-            for (const auto& var_name : var_output_names_) {
-                std::cout << "  - " << var_name << std::endl;
+            if (Logger::GetLogger()->GetLogLevel() == LogLevel::DEBUG) {
+                ss.str(""); ss << "BMI instance initialized successfully" << std::endl;
+                LOG(LogLevel::DEBUG, ss.str());
+                ss.str(""); ss << "Time step: " << time_step_.count() << " seconds" << std::endl;
+                LOG(LogLevel::DEBUG, ss.str());
+                ss.str(""); ss << "Available output variable names:" << std::endl;
+                LOG(LogLevel::DEBUG, ss.str());
+                for (const auto& var_name : var_output_names_) {
+                    ss.str(""); ss << "  - " << var_name << std::endl;
+                    LOG(LogLevel::DEBUG, ss.str());
+                }
             }
         } catch (const std::exception& ex) {
-            std::cerr << "[ngen error] Error initializing BMI instance: " << ex.what() << std::endl;
+            ss.str(""); ss << "Error initializing BMI instance: " << ex.what() << std::endl;
+            LOG(LogLevel::FATAL, ss.str());
             throw;
         }
 
         // Log successful constructor exit
-        std::cout << "[ngen debug] Exiting ForcingsEngineDataProvider constructor" << std::endl;
+        ss.str(""); ss << "Exiting ForcingsEngineDataProvider constructor" << std::endl;
+        LOG(LogLevel::DEBUG, ss.str());
+
     }
 
     //! Ensure a variable is available, appending the suffix if needed

include/forcing/NetCDFPerFeatureDataProvider.hpp

@@ -128,7 +128,7 @@ namespace data_access
         TimeUnit time_unit;                             // the unit that time was stored as in the file
         double time_stride;                             // the amount of time between stored time values
         utils::StreamHandler log_stream;
-
+        std::string file_path;
 
         std::shared_ptr<netCDF::NcFile> nc_file;
 

include/realizations/catchment/Bmi_Module_Formulation.hpp

@@ -486,8 +486,6 @@ namespace realization {
         /** A configured mapping of BMI model variable names to standard names for use inside the framework. */
         std::map<std::string, std::string> bmi_var_names_map;
         bool model_initialized = false;
-        bool unitGetValueErrLogged = false;
-        bool unitGetValuesErrLogged = false;
 
         std::vector<std::string> OPTIONAL_PARAMETERS = {
                 BMI_REALIZATION_CFG_PARAM_OPT__USES_FORCINGS

include/realizations/catchment/Bmi_Multi_Formulation.hpp

@@ -583,6 +583,15 @@ namespace realization {
                 //TODO: After merge PR#405, try re-adding support for index
                 return nested_module->get_value(selector);
             }
+            catch (data_access::unit_conversion_exception &uce) {
+                // We asked for it as a dimensionless quantity, "1", just above
+                static bool no_conversion_message_logged = false;
+                if (!no_conversion_message_logged) {
+                    no_conversion_message_logged = true;
+                    LOG("Emitting output variables from Bmi_Multi_Formulation without unit conversion - see NGWPC-7604", LogLevel::WARNING);
+                }
+                return uce.unconverted_values[0];
+            }
             // If there was any problem with the cast and extraction of the value, throw runtime error
             catch (std::exception &e) {
                 std::string throw_msg; throw_msg.assign("Multi BMI formulation can't use associated data provider as a nested module"

include/realizations/catchment/Catchment_Formulation.hpp

@@ -7,6 +7,8 @@
 #include <HY_CatchmentArea.hpp>
 #include "GenericDataProvider.hpp"
 
+#include "Logger.hpp"
+
 #define DEFAULT_FORMULATION_OUTPUT_DELIMITER ","
 
 namespace realization {
@@ -42,16 +44,23 @@ namespace realization {
          */
         static void config_pattern_substitution(geojson::PropertyMap &properties, const std::string &key,
                                                 const std::string &pattern, const std::string &replacement) {
+            std::stringstream ss;
             auto it = properties.find(key);
             // Do nothing and return if either the key isn't found or the associated property isn't a string
             if (it == properties.end() || it->second.get_type() != geojson::PropertyType::String) {
-                std::cout << "[DEBUG] Skipping pattern substitution for key: " << key << " (not found or not a string)" << std::endl;
+                ss.str("");
+                ss << "Skipping pattern substitution for key: " << key << " (not found or not a string)" << std::endl;
+                LOG(ss.str(), LogLevel::DEBUG);
                 return;
             }
 
             std::string value = it->second.as_string();
-            std::cout << "[DEBUG] config_pattern_substitution Performing pattern substitution for key: " << key << ", pattern: " << pattern << ", replacement: " << replacement << std::endl;
-//            std::cout << "[DEBUG] Original value: " << value << std::endl;
+            ss.str("");
+            ss << "config_pattern_substitution Performing pattern substitution for key: " << key << ", pattern: " << pattern << ", replacement: " << replacement << std::endl;
+            LOG(ss.str(), LogLevel::DEBUG);
+//            ss.str("");
+//            ss << "Original value: " << value << std::endl;
+//            LOG(ss.str(), LogLevel::DEBUG);
 
             size_t id_index = value.find(pattern);
             while (id_index != std::string::npos) {
@@ -63,7 +72,9 @@ namespace realization {
             properties.erase(key);
             properties.emplace(key, geojson::JSONProperty(key, value));
 
-//            std::cout << "[DEBUG] Substitution result for key: " << key << " -> " << value << std::endl;
+//            ss.str("");
+//            ss << "Substitution result for key: " << key << " -> " << value << std::endl;
+//            LOG(ss.str(), LogLevel::DEBUG);
         }
 
             /**