Restructure loggers and log calls

CMakeLists.txt

@@ -80,6 +80,10 @@ check_symbol_exists(getopt_long getopt.h HAVE_GETOPT)
 include(GetVersion)
 GetVersion(${PROJECT_SOURCE_DIR} "DPSIM")
 
+if (CMAKE_BUILD_TYPE MATCHES Debug)
+	set(DEBUG_BUILD ON)
+endif()
+
 # Deprecated build options
 # TODO: Remove deprecated options in future release
 option(WITH_EIGEN_MODULE     "Fetch Eigen3 as module (deprecated option)" OFF)

docs/hugo/content/en/docs/Development/Guidelines.md

@@ -7,9 +7,39 @@ This is a summary of general guidelines for the development of DPsim.
 
 ## Logging
 
-Debug or trace should be the default log level for information that might be nice to have but not necessary for every simulation case.
-
-Calls to the logger that might occur during simulation must use spdlog macros, like SPDLOG_LOGGER_INFO.
+There are two ways to log information in DPsim: The `CPS::Logger` (called the **Text Logger**), which can write to `.log` files and to the CLI, as well as the `CPS::DataLogger` (called the **Data Logger**), which can write to `.csv` files.
+
+### Log Levels
+The log levels that can be used with the Text Logger are as follows:
+- `off` - no Text Logger output at all, recommended to use e.g. when running case studies where exclusively the simulation results should be logged
+- `error` - all errors
+- `warn` - all warnings
+- `info` - logging of information that is basic and that is logged only once before/after the simulation
+- `debug` - logging of information for debugging (extended static information, e.g. initialization values, matrix stamps, subcomponents)
+- `trace` - logging of information in each simulation step
+
+While the Data Logger does not have any log levels (just a boolean flag to enable or disable the logger),
+there are some Data Loggers that are only activated when the object owning the Data Logger is also configured to use a certain log level.
+E.g., the `<SimName>_LeftVector.csv` and `<SimName>_RightVector.csv` will only be generated when the Simulation Text Logger is set to `trace` level.
+
+Logging with the Text Logger should always happen using the `SPDLOG_LOGGER_<LEVEL>` macros.
+
+### Examples
+The Text Loggers in DPsim are grouped into three categories:
+- `Simulation`: All the Text Loggers logging into `Simulation.log`
+- `Component`: All the Text Loggers logging into `Components.log`
+- `Debug`: Text Loggers used for debugging purposes, each creating their own log files
+
+The following table provides an overview on what output is produced in each category on different log levels:
+
+| Log Level    | `Simulation` Text Logger  | `Component` Text Logger | `Debug` Text Loggers | Data Loggers |
+|--------------|---------------------------|-------------------------|----------------------|--------------|
+| `off`        | -                         | -                       | -                    |Only log that is explicitly requested by the user, e.g. through `DataLogger::log_attribute` or `Simulation::logStepTimes`|
+| `error`      | Errors that will lead to a program crash or invalidate the simulation results | Errors that will lead to a program crash or invalidate the simulation results | Errors that will lead to a program crash or invalidate the simulation results | Only log that is explicitly requested by the user, e.g. through `DataLogger::log_attribute` or `Simulation::logStepTimes`|
+| `warn`       | Problems that might lead to invalid results, but will likely not lead to a crash | Problems that might lead to invalid results, but will likely not lead to a crash | Problems that might lead to invalid results, but will likely not lead to a crash |  Only log that is explicitly requested by the user, e.g. through `DataLogger::log_attribute` or `Simulation::logStepTimes`|
+| `info`       | e.g. Summary of number of network and virtual nodes, Simulation configuration / domain| e.g. Parameters set through `setParameters`, connections to network nodes | e.g. `CSVReader.log`, whenever a `CSVReader` is used | Only log that is explicitly requested by the user, e.g. through `DataLogger::log_attribute` or `Simulation::logStepTimes`|
+| `debug`      | e.g. System matrices, Scheduler log, More details about the used solver | e.g. Component initialization, subcomponents, snubber components | e.g. `CIMReader.log`, whenever a `CIMReader` is used| e.g. iteration count for iterative solvers in `<SimName>.csv`|
+| `trace`      | Information that changes on each simulation step | e.g. voltages / currents calculated in `mnaUpdateCurrent`/`mnaUpdateVoltage`|-|e.g. `<SimName>_LeftVector.csv`, `<SimName>_RightVector.csv`, `<SimName>_InitLeftVector.csv`, `<SimName>_InitRightVector.csv`|
 
 ## Creating New Releases
 
@@ -23,4 +53,4 @@ A new version of DPsim has to be indicated as follows:
 - Update sonar-project.properties
 
 Due to the creation of a new tag, a new PyPi package will be deployed automatically.
-To release an updated Docker image, the container workflow needs to be triggered manually.
+To release an updated Docker image, the container workflow needs to be triggered manually.

docs/hugo/content/en/docs/Overview/Attributes/index.md

@@ -12,19 +12,19 @@ In general, attributes are instances of the `Attribute<T>` class, but they are u
 
 Through the template parameter `T` of the `Attribute<T>` class, attributes can have different value types, most commonly `Real`, `Complex`, `Matrix`, or `MatrixComp`. Additionally, attributes can fall into one of two categories:
 **Static** attributes have a fixed value which can only be changed explicitly through the attribute's `set`-method or through a mutable reference obtained through `get`.
-**Dynamic** attributes on the other hand can dynamically re-compute their value from other attributes every time they are read. This can for example be used to create a scalar attribute of type `Real` whose value always contains the magnitude of another, different attribute of type `Complex`. 
+**Dynamic** attributes on the other hand can dynamically re-compute their value from other attributes every time they are read. This can for example be used to create a scalar attribute of type `Real` whose value always contains the magnitude of another, different attribute of type `Complex`.
 
 Any simulation component or class which inherits from `IdentifiedObject` contains an instance of an `AttributeList`.
 This list can be used to store all the attributes present in this component and later access them via a `String` instead of having to use the member variable directly.
-For reasons of code clarity and runtime safety, the member variables should still be used whenever possible. 
+For reasons of code clarity and runtime safety, the member variables should still be used whenever possible.
 
 ## Creating and Storing Attributes
 Normally, a new attribute is created by using the `create` or `createDynamic` method of an `AttributeList` object.
 These two methods will create a new attribute of the given type and insert it into the `AttributeList` under the given name. After the name, `create` can take an additional parameter of type `T` which will be used as the initial value for this attribute.
 Afterwards, a pointer to the attribute is returned which can then be stored in a component's member variable. Usually this is done in the
 component's constructor in an initialization list:
 
-```cpp    
+```cpp
 /// Component class Base::Ph1::PiLine
 
 public:
@@ -53,7 +53,7 @@ Simulation::Simulation(String name,	Logger::Level logLevel) :
 	mTimeStep(AttributeStatic<Real>::make(0.001)),
 	mSplitSubnets(AttributeStatic<Bool>::make(true)),
 	mSteadyStateInit(AttributeStatic<Bool>::make(false)),
-	//... 
+	//...
 {
 	// ...
 }
@@ -83,7 +83,7 @@ Real read3 = **attr; //read3 = 0.003
 ```
 
 ## Working with Dynamic Attributes
-In general, dynamic attributes can be accessed via the same `get` and `set`-methods described above for static attributes. However, 
+In general, dynamic attributes can be accessed via the same `get` and `set`-methods described above for static attributes. However,
 dynamic attributes can additionally have **dependencies** on other attributes which affect the behavior of these methods.
 Usually, this is used to dynamically compute the attribute's value from the value of another attribute. In the simplest case, a dynamic
 attribute can be set to **reference** another (static or dynamic) attribute using the `setReference`-method. After this method has been called,
@@ -150,7 +150,7 @@ required attribute pointer, one can either directly access the public member var
 auto r1 = DP::Ph1::Resistor::make("r_1");
 r1->setParameters(5);
 
-auto logger = DataLogger::make("simName");
+auto logger = CPS::DataLogger::make("simName");
 // Access the attribute through the member variable
 logger->logAttribute("i12", r1->mIntfCurrent);
 
@@ -187,4 +187,4 @@ void DP::Ph1::Inductor::mnaAddPostStepDependencies(
 }
 ```
 Here, the MNA post step depends on the solution vector of the system, `leftVector`, and modifies `mIntfVoltage` and `mIntfCurrent`.
-Therefore, this task needs to be scheduled after the system solution that computes `leftVector` and before tasks that require the voltage and current interface vectors of the inductance, e.g. the task logging these values.
+Therefore, this task needs to be scheduled after the system solution that computes `leftVector` and before tasks that require the voltage and current interface vectors of the inductance, e.g. the task logging these values.

dpsim-models/include/dpsim-models/CIM/Reader.h

@@ -154,8 +154,8 @@ namespace CIM {
 	public:
 		/// Creates new reader with a name for logging.
 		/// The first log level is for the reader and the second for the generated components.
-		Reader(String name,
-			Logger::Level logLevel = Logger::Level::info,
+		Reader(Logger::Level logLevel = Logger::Level::info,
+			Logger::Level cliLevel = Logger::Level::off,
 			Logger::Level componentLogLevel = Logger::Level::off);
 		///
 		virtual ~Reader();

dpsim-models/include/dpsim-models/CSVReader.h

@@ -52,13 +52,13 @@ namespace CPS {
 		enum class DataFormat { HHMMSS, SECONDS, HOURS, MINUTES };
 
 		///
-		CSVReader(String name, std::list<fs::path> path, Logger::Level logLevel);
+		CSVReader(std::list<fs::path> path, Logger::Level logLevel, Logger::Level cliLevel = Logger::Level::off);
 		///
-		CSVReader(String name, String path, Logger::Level logLevel);
+		CSVReader(String path, Logger::Level logLevel, Logger::Level cliLevel = Logger::Level::off);
 		///
-		CSVReader(String name, std::list<fs::path> path, std::map<String, String>& assignList, Logger::Level logLevel);
+		CSVReader(std::list<fs::path> path, std::map<String, String>& assignList, Logger::Level logLevel, Logger::Level cliLevel = Logger::Level::off);
 		///
-		CSVReader(String name, String path, std::map<String, String>& assignList, Logger::Level logLevel);
+		CSVReader(String path, std::map<String, String>& assignList, Logger::Level logLevel, Logger::Level cliLevel = Logger::Level::off);
 
 		///	convert HH:MM:SS format timestamp into total seconds.
 		///	e.g.: 00 : 01 : 00 -- > 60.

dpsim-models/include/dpsim-models/Config.h.in

@@ -16,3 +16,4 @@
 #cmakedefine WITH_NUMPY
 #cmakedefine WITH_KLU
 #cmakedefine CGMES_BUILD
+#cmakedefine DEBUG_BUILD

dpsim/include/dpsim/DataLogger.h → dpsim-models/include/dpsim-models/DataLogger.h

@@ -12,45 +12,50 @@
 #include <iostream>
 #include <fstream>
 
-#include <dpsim/Definitions.h>
-#include <dpsim/Scheduler.h>
 #include <dpsim-models/Filesystem.h>
 #include <dpsim-models/PtrFactory.h>
 #include <dpsim-models/Attribute.h>
 #include <dpsim-models/SimNode.h>
 #include <dpsim-models/Task.h>
 
-namespace DPsim {
+namespace CPS {
 
 	class DataLogger : public SharedFactory<DataLogger> {
 
 	protected:
 		std::ofstream mLogFile;
 		String mName;
+		/// FIXME: The enabled-parameter cannot be changed midway through the simulation
+		/// Instead of setting this to false, the logger should not be created at all to reduce function call overhead
 		Bool mEnabled;
 		UInt mDownsampling;
 		fs::path mFilename;
 
 		std::map<String, CPS::AttributeBase::Ptr> mAttributes;
 
-		void logDataLine(Real time, Real data);
-		void logDataLine(Real time, const Matrix& data);
-		void logDataLine(Real time, const MatrixComp& data);
-
 	public:
 		typedef std::shared_ptr<DataLogger> Ptr;
 		typedef std::vector<DataLogger::Ptr> List;
 
 		DataLogger(Bool enabled = true);
 		DataLogger(String name, Bool enabled = true, UInt downsampling = 1);
 
+		void logDataLine(Real time, Real data);
+		void logDataLine(Real time, std::vector<Real> data);
+		void logDataLine(Real time, const Matrix& data);
+		void logDataLine(Real time, const MatrixComp& data);
+
 		void open();
 		void close();
 		void reopen() {
 			close();
 			open();
 		}
 
+		const String& name() const {
+			return mName;
+		}
+
 		void logPhasorNodeValues(Real time, const Matrix& data, Int freqNum = 1);
 		void logEMTNodeValues(Real time, const Matrix& data);
 
@@ -72,7 +77,7 @@ namespace DPsim {
 				for (auto attr : logger.mAttributes) {
 					mAttributeDependencies.push_back(attr.second);
 				}
-				mModifiedAttributes.push_back(Scheduler::external);
+				mModifiedAttributes.push_back(nullptr); //nullptr = Scheduler::external, but this cannot be used because the scheduler is not linked yet.
 			}
 
 			void execute(Real time, Int timeStepCount);

dpsim-models/include/dpsim-models/Logger.h

@@ -1,14 +1,16 @@
-/* Copyright 2017-2021 Institute for Automation of Complex Power Systems,
- *                     EONERC, RWTH Aachen University
- *
- * This Source Code Form is subject to the terms of the Mozilla Public
- * License, v. 2.0. If a copy of the MPL was not distributed with this
- * file, You can obtain one at https://mozilla.org/MPL/2.0/.
- *********************************************************************************/
+// SPDX-License-Identifier: Apache-2.0
 
 #pragma once
 
-#define SPDLOG_ACTIVE_LEVEL SPDLOG_LEVEL_INFO
+#include <dpsim-models/Config.h>
+
+#if defined(DEBUG_BUILD)
+	#define SPDLOG_ACTIVE_LEVEL SPDLOG_LEVEL_TRACE
+#else
+	#define SPDLOG_ACTIVE_LEVEL SPDLOG_LEVEL_INFO
+#endif
+#define SPDLOG_DISABLE_DEFAULT_LOGGER
+
 #include <spdlog/spdlog.h>
 
 #if defined(SPDLOG_VER_MAJOR) && SPDLOG_VER_MAJOR >= 1
@@ -18,6 +20,9 @@
 #endif
 
 #include <spdlog/fmt/ostr.h>
+#include <spdlog/sinks/null_sink.h>
+#include <spdlog/sinks/stdout_color_sinks.h>
+#include "spdlog/sinks/base_sink.h"
 
 #include <dpsim-models/Definitions.h>
 #include <dpsim-models/MathUtils.h>
@@ -30,20 +35,33 @@ namespace CPS {
 		using Level = spdlog::level::level_enum;
 		using Log = std::shared_ptr<spdlog::logger>;
 
+		enum class LoggerType {
+			SIMULATION,
+			COMPONENT,
+			DEBUG
+		};
+
+		/// Holds the file sinks shared by all simulation loggers
+		static std::map<std::string, spdlog::sink_ptr, std::less<>> mFileSinkRegistry;
+		/// Holds the stdout cli sink shared by all loggers
+		static spdlog::sink_ptr mStdoutSink;
+		/// Holds the stderr cli sink shared by all loggers
+		static spdlog::sink_ptr mStderrSink;
+
 	private:
-		static Log create(const std::string &name, Level filelevel = Level::info, Level clilevel = Level::off);
+		static Log create(Logger::LoggerType type, const std::string &name, const std::string &fileName, Level filelevel, Level clilevel);
 
 	public:
-		Logger();
-		~Logger();
+		Logger() = default;
+		~Logger() = default;
 
 		static String prefix();
 		static String logDir();
 		static void setLogDir(String path);
 
 		// #### SPD log wrapper ####
 		///
-		static Log get(const std::string &name, Level filelevel = Level::info, Level clilevel = Level::off);
+		static Log get(LoggerType type, const std::string &name, Level filelevel = Level::info, Level clilevel = Level::off);
 		///
 		static void setLogLevel(std::shared_ptr<spdlog::logger> logger, Logger::Level level);
 		///
@@ -58,10 +76,54 @@ namespace CPS {
 		static String phasorToString(const Complex& num);
 		static String complexToString(const Complex& num);
 		static String realToString(const Real& num);
-		
+
 		static String getCSVColumnNames(std::vector<String> names);
 		static String getCSVLineFromData(Real time, Real data);
 		static String getCSVLineFromData(Real time, const Matrix& data);
 		static String getCSVLineFromData(Real time, const MatrixComp& data);
+
+		class dpsim_sink : public spdlog::sinks::base_sink <std::mutex>
+		{
+		private:
+			spdlog::sink_ptr mFileSink;
+			spdlog::sink_ptr mStdoutSink;
+			spdlog::sink_ptr mStderrSink;
+			Level mFileLevel;
+			Level mCliLevel;
+		public:
+			dpsim_sink(spdlog::sink_ptr fileSink, spdlog::sink_ptr stdoutSink, spdlog::sink_ptr stderrSink, Level fileLevel, Level cliLevel) :
+				spdlog::sinks::base_sink<std::mutex>(),
+				mFileSink(fileSink),
+				mStdoutSink(stdoutSink),
+				mStderrSink(stderrSink),
+				mFileLevel(fileLevel),
+				mCliLevel(cliLevel) { };
+		protected:
+			void sink_it_(const spdlog::details::log_msg& msg) override
+			{
+				if (mFileSink && msg.level >= mFileLevel) {
+					mFileSink->log(msg);
+				}
+				if (mStdoutSink && msg.level >= mCliLevel && msg.level < Level::warn) {
+					mStdoutSink->log(msg);
+				}
+				if (mStderrSink && msg.level >= mCliLevel && msg.level >= Level::warn) {
+					mStderrSink->log(msg);
+				}
+			}
+
+			void flush_() override
+			{
+				if (mFileSink) {
+					mFileSink->flush();
+				}
+				if (mStdoutSink) {
+					mStdoutSink->flush();
+				}
+				if (mStderrSink) {
+					mStderrSink->flush();
+				}
+			}
+		};
 	};
 }

dpsim-models/include/dpsim-models/MNASimPowerComp.h

@@ -15,6 +15,9 @@ namespace CPS {
 		Bool mHasPreStep;
 		Bool mHasPostStep;
 
+	protected:
+		Real mSimulationTime;
+
 	public:
 		using Type = VarType;
 		using Ptr = std::shared_ptr<MNASimPowerComp<VarType>>;