Logging Architecture - Base Logger

## Custom logging facade

The design outlined is based on the development of a bespoke logging facade, tailored specifically to meet our unique requirements. Recognizing that components from this repository may eventually be incorporated into different software, we must consider this during development.
Consequently, it is essential to implement an adapter capable of redirecting all events from our custom facade to SLF4J. While this adapter may not be utilized directly within this repository, it will be available for any projects that rely on modules from our repository.

### Why we need a custom logging facade

To effectively aggregate logging events and messages from both our modules and third-party libraries, the use of a logging facade is necessary. In the Java ecosystem, [SLF4J](https://www.slf4j.org/index.html) is widely recognized as the predominant logging facade, primarily due to its ability to consolidate logs from various logging libraries. Another crucial aspect of a logging facade is the distinction between its API and its implementation. In this context, Log4J2's API module stands out as it can function as a facade with a custom logging implementation. Log4J2 has certain advantages over SLF4J, including [additional features](https://logging.apache.org/log4j/2.x/#api-separation). Additionally, Java offers a basic logging facade through `java.lang.System.Logger`.

However, each of these options comes with its own set of limitations, leading us to the conclusion that a custom logging facade is the most suitable solution for our needs:

- SLF4J introduced a fluent API supporting lambdas (Supplier for messages) from version 2 onwards. However, this API is distinct from the classic one to avoid disrupting the standard SLF4J API. This separation results in a less than ideal API definition.
- The maintenance of SLF4J is primarily shouldered by a single individual, raising concerns about its sustainability and responsiveness to evolving needs.
- The `java.lang.System.Logger` offers a very basic API, lacking several functionalities that are essential for our purposes.
- While the Log4J2 API is extensive, encompassing over 100 classes, it presents challenges in implementation due to its complexity. Moreover, many of its functionalities are surplus to our requirements.

Considering these factors, a tailor-made logging facade emerges as the optimal approach, ensuring that our specific needs are addressed effectively.

## Collecting all logging messages and events

We must collect all logging messages from all loggers on the classpath at runtime. There are several patterns that support collecting log messages:
- `java.lang.System.Logger` is just a facade that forwards all messages to an underlying logger
- SLF4J provides Adapters to collect the logging from several logging frameworks.
- SLF4J is often used directly and all messages that are created in SLF4 or passed to SLF4J can easily be forwarded to any concrete logging implementation

The following diagram shows a concrete idea how the logging architecture can look like in future:


The next diagram shows a more simple version:


## API of our logging facade

In the realm of logging, it's pivotal to broaden our perspective from merely logging messages to logging events. A logging event encompasses much more than just a message; it's a rich source of information. Below are the key features that any modern logging system or facade should incorporate:

1. **Support for Message Placeholders**: Our custom facade should allow messages with `{}` placeholders, similar to SLF4J. This should include support for varargs... and handle various data types, including all primitives, `String`, `null`, `Supplier`, and other object types.

2. **Event Origin Tracking**: It's essential to trace the class from where a logging event originates, a standard practice in most logging frameworks. Further details like the method, line number, etc., are worth considering, although their extraction can be time-consuming and should be discussed further.

3. **Timestamp Inclusion**: Each logging event must be timestamped to mark its creation time accurately.

4. **Thread Identification**: The system should be able to identify and record the thread executing the logging call.

5. **Throwable Cause Handling**: The facade must accommodate a `Throwable` object to represent the cause of a logging event.

6. **Log Levels**: It should support various logging levels, including `ERROR`, `WARN`, `INFO`, `DEBUG`, and `TRACE`.

7. **Marker Support**: The facade should utilize markers (identified by a `String` name) judiciously. Markers are optional parameters and should be used only when appropriate. For instance, an `ERROR` marker is redundant and can be managed by the event's log level.

8. **Key-Value Based Metadata**: The system should allow for key-value metadata, where both key and value are `String`-based. This feature is crucial for providing additional context to a logging event, such as the current system, software version, or transaction ID. Like message arguments, `Supplier` should be supported for metadata values.

9. **Mapped Diagnostic Context (MDC) Support**: Our facade should integrate MDC on both a global and thread-local level. Any data stored in the MDC at the time of a logging event's creation should be automatically included in the event's metadata.

These features collectively ensure that our custom logging facade not only captures detailed information about each logging event but also remains versatile and efficient in diverse logging scenarios.

Based on that definitions a logging event look like:

```
public enum Level {
ERROR, WARN, INFO, DEBUG, TRACE
}

public record DefaultLogEvent(
@NonNull Level level,
@NonNull String loggerName,
@NonNull String threadName,
long timestamp,
@NonNull LogMessage message,
@Nullable Throwable throwable,
@Nullable Marker marker,
@NonNull Map context)
implements LogEvent {}
```

You'll find the api in the platform-sdk [swilrds-logging module](https://github.com/hashgraph/hedera-services/tree/develop/platform-sdk/swirlds-logging/src/main/java/com/swirlds/logging/api)

## Logging output

The presented architecture intentionally omits specifics regarding the appearance of the logging output. This design choice is a significant advantage, allowing for a high degree of flexibility. Ultimately, it's the responsibility of the chosen logging implementation—log4j2 is provided as an example in the diagram—to determine the nature of the output based on its configuration. This architecture is versatile enough to support a wide range of output options, ranging from simple console outputs to integration with sophisticated centralized systems like Graylog or Kibana.

It's important to note that the specifics of the output formats are beyond the scope of this issue. The architecture is designed to be agnostic to output formats, ensuring that it can adapt to various logging requirements and preferences. This approach allows users to customize the logging output to their specific needs without being constrained by the architecture's design. Such flexibility is key to ensuring the architecture's broad applicability and ease of integration into diverse environments.

## Possible feature in future: Using logs for tracing

In microservice-based architectures, tracing is a widely adopted practice that enables tracking the flow of requests across multiple services. This tracking is typically implemented by incorporating tracing metadata into the request and response messages of the systems, often within HTTP headers. Leveraging a logging provider that supports Mapped Diagnostic Context (MDC) can further enhance tracing. It allows for the continuation of tracing within a service by appending the tracing metadata to all related log events for a specific request.

Adopting this approach in our system offers numerous benefits. By integrating tracing information into our log events, we can analyze and understand the flow of interactions within our system more effectively. For a practical guide on simple tracing implementation in logging, you can refer to [Datadog's documentation](https://docs.datadoghq.com/tracing/other_telemetry/connect_logs_and_traces/java/?tab=log4j2). Additionally, it's noteworthy that the W3C is developing a standard for tracing HTTP headers ([Trace Context](https://w3c.github.io/trace-context/#abstract)), which is anticipated to be utilized by frameworks like OpenTelemetry, as outlined in their [logging specification](https://opentelemetry.io/docs/reference/specification/logs/#trace-context-in-legacy-formats).

> [!NOTE]
> The concept of tracing is mentioned here to provide a comprehensive understanding of the potential enhancements to our system. While there are no immediate plans to implement this feature, it remains a consideration for future specialized use cases. Further details can be explored in [this GitHub issue](https://github.com/hashgraph/hedera-services/issues/7014).

As we progress with our local Prometheus and Grafana setup, exploring the possibility of integrating tracing views directly into Grafana for developers is an exciting prospect. This integration could provide a more intuitive and visual means of monitoring and analyzing system flows, similar to the example shown in the provided screenshot.


Such an integration would not only enhance the developer experience but also offer valuable insights for system optimization and troubleshooting.

## Configuration

Our system requires a straightforward file-based configuration for logging, akin to what is seen in Spring Boot. This configuration should be simpler and less extensive than the XML-based configuration available in Log4J. Essentially, it needs to provide options to enable or disable file and console logging. Additionally, setting logging levels for specific packages or classes should be straightforward and intuitive.

We recomment to maintain a separate `logging.properties` file alongside the main settings file. This separation has several advantages:

1. **Frequent Changes**: Logging settings often change during development, unlike other properties which are relatively static.
2. **Runtime Reloadability**: It's crucial that the logging configuration can be reloaded at runtime, enabling adjustments to logging levels for specific classes or packages without the need to reload the entire settings.
3. **Isolation of Configurations**: By keeping the logging configuration separate, we ensure that changes in logging do not affect other system configurations.

For practicality, the `logging.properties` file should be set to reload every second, ensuring up-to-date logging configurations at all times.

Regarding the format of the logging configuration, it should be user-friendly and self-explanatory. Here's an improved representation of the syntax for setting logging levels:

```properties
# Global default logging level
logging.level = INFO

# Specific logging levels for packages or classes
logging.level.com.swirlds.common.crypto = DEBUG
logging.level.com.swirlds.common.crypto.Signature = WARN
logging.level.com.hashgraph = WARN
```

This configuration demonstrates how to set a global default logging level (`INFO`). It also illustrates how to specify logging levels for packages and classes. For example, everything under `com.swirlds.common.crypto` is set to `DEBUG`, except for `com.swirlds.common.crypto.Signature`, which is explicitly set to `WARN`. Similarly, all loggers within `com.hashgraph` default to `WARN`. This approach ensures that loggers inherit the most specific level defined in the configuration, providing both flexibility and precision in logging management.

To provide developers with more control and flexibility in logging, we propose introducing filters for markers. This feature would allow developers to focus on log messages associated with specific markers, regardless of the logger's log level. If there's demand for such functionality among developers, the configuration for marker filters could be structured as follows:

```properties
# Marker filter configuration
logging.marker.CONFIG = ENABLED
logging.marker.CRYPTO = DISABLED
logging.marker.OTHER = DEFAULT
```

In this configuration, the `logging.marker.NAME` pattern is used, where `NAME` represents the marker's name, and the value can be set to `ENABLED`, `DISABLED`, or `DEFAULT`. For example, `logging.marker.CONFIG = ENABLED` would ensure that all log messages tagged with the `CONFIG` marker are displayed, irrespective of their log level.

A typical logging configuration file, incorporating these marker filters, might look like this:

```properties
# General logging level configuration
logging.level = INFO
logging.level.com.swirlds.common.crypto = DEBUG
logging.level.com.swirlds.common.crypto.Signature = WARN
logging.level.com.hashgraph = WARN

# Marker-specific logging configuration
logging.marker.CONFIG = ENABLED

# Additional handler configuration
logging.handler.NAME.level = WARN
```

To further refine our logging system, we have incorporated the concept of handlers. These handlers allow for more granular control over logging behavior. Each handler can be distinctly named and configured using the prefix `logging.handler.NAME`, where `NAME` is a unique identifier for the handler. This structure enables us to apply handler-specific settings. For instance, `logging.handler.NAME.level` can be used to set the logging level for a specific handler. All previously discussed features, such as marker filters and log level settings, are also applicable to these handlers.

A particularly useful feature of handlers is the `inheritLevels` property. This boolean property determines whether the handler should inherit the default level configurations set globally. By default, `inheritLevels` is set to `true`. However, it can be turned off to create a handler that focuses exclusively on a specific aspect of logging, such as a particular marker. For example, if you need a handler that only logs entries marked with the `CRYPTO` marker, your configuration would look like this:

```properties
# Handler specific for CRYPTO marker
logging.handler.CRYPTO_FILE.level = OFF
logging.handler.CRYPTO_FILE.marker.CRYPTO = ENABLED
```

In this configuration, the `CRYPTO_FILE` handler is set to ignore the global log level settings (`level = OFF`) but is specifically enabled to log messages tagged with the `CRYPTO` marker (`marker.CRYPTO = ENABLED`). This setup allows for the creation of dedicated log files or outputs for specific types of log messages, providing a focused view that can be particularly useful in complex systems or during specific types of analysis.

Overall, the introduction of handlers adds a layer of customization to our logging framework, enabling developers to tailor the logging system to their specific needs, whether it's for general application logging or for monitoring specialized aspects of the system.

This approach provides a comprehensive yet straightforward configuration model, allowing developers to easily tailor the logging system to meet their current requirements. The combination of general log levels, marker filters, and handler-specific settings ensures a highly customizable and efficient logging setup.

## Performance

Different logging targets (file logging, ...) have an impact on the performance. Therefore we should have a general look at the performance impact and check if we can define "priorities" for targets: In general a file logging is good enough and we should guarantee that a file logging is up to date. But a Loki logging might be working with a Queue and a special thread that sends the logging to a Loki endpoint. By doing so the logging might be slower (speaking in ms) but do not take so much performance.

The repository https://github.com/OpenElements/java-logger-benchmark contains several JMH benchmarks for all the logger libraries that are currently part of our discussed. Here are some test results:

The following table contains the results of the benchmark for logging a simple "hello world" message:

| Logger | Logging Appender | Operations per second |
|-------------------|------------------------|------------------------:|
| Chronicle Logger | FILE_ASYNC | 2224759 |
| Log4J2 | FILE_ASYNC | 902715 |
| SLF4J Simple | FILE | 300924 |
| Log4J2 | FILE | 163218 |
| Java Util Logging | FILE | 103076 |
| Log4J2 | FILE_AND_CONSOLE | 89460 |
| Java Util Logging | CONSOLE | 83442 |
| Log4J2 | CONSOLE | 72365 |
| Log4J2 | FILE_ASYNC_AND_CONSOLE | 64143 |
| Java Util Logging | FILE_AND_CONSOLE | 49268 |

The following table contains the results of the benchmark for executing the `LogLikeHell` Runnable that contains all possible logging operations:

| Logger | Logging Appender | Operations per second |
|-------------------|------------------------|----------------------:|
| Chronicle Logger | FILE_ASYNC | 57270 |
| Log4J2 | FILE_ASYNC | 33770 |
| Log4J2 | FILE | 9880 |
| Java Util Logging | FILE | 6373 |
| SLF4J Simple | FILE | 6091 |
| Java Util Logging | FILE_AND_CONSOLE | 1918 |
| Log4J2 | FILE_ASYNC_AND_CONSOLE | 1610 |
| Java Util Logging | CONSOLE | 1539 |
| Log4J2 | FILE_AND_CONSOLE | 1436 |
| Log4J2 | CONSOLE | 985 |

The results show that async file logging is the fastest logging and based on the scenario it is much faster than synced logging but it introduces additional transitive dependencies. Console logging should be deactivated for production.

While Chronicle Logger is the fasted logger it provides a binary output that need to parsed in a special way. Based on that Log4J2 with async support (based on Disrupter library) might be the best option.

## Test support

Here's an improved version of your documentation, focusing on clarity and the functionality of the `WithLoggingMirror` annotation in JUnit 5:

To enhance our testing capabilities, we've introduced the `WithLoggingMirror` annotation in JUnit 5. This annotation is designed to inject a `LoggingMirror` instance into a test method or test class. It plays a crucial role in facilitating the inspection and verification of logging events generated during a test. Key features and considerations of the `WithLoggingMirror` annotation are:

- **Isolated Test Execution**: Tests marked with the `WithLoggingMirror` annotation are configured to run sequentially, not in parallel. This ensures that each test has exclusive access to its instance of `LoggingMirror`, thereby preventing potential conflicts or inaccuracies arising from concurrent test executions.

- **Logging Event Analysis**: The `LoggingMirror` instance serves as a tool for capturing and analyzing logging events within the test scope. It enables developers to assert and validate the logging behavior of the system under test, ensuring that logging events are generated and recorded as expected.

- **Enhanced Testing Precision**: By providing an isolated and controlled environment for each test, the `WithLoggingMirror` annotation contributes to more precise and reliable testing outcomes. This is particularly beneficial for tests where logging behavior is a critical aspect of the functionality being verified.

- **Usage Example**: To utilize this annotation, simply annotate your test class or method with `@WithLoggingMirror`. This automatically injects a `LoggingMirror` instance, allowing you to monitor and assert specific logging events that occur during the test execution.

## Open tasks:

- [ ] #5457
- [ ] https://github.com/hashgraph/hedera-services/issues/9097
- [ ] https://github.com/hashgraph/hedera-services/issues/10907
- [ ] https://github.com/hashgraph/hedera-services/issues/10908
- [ ] https://github.com/hashgraph/hedera-services/issues/10909
- [ ] https://github.com/hashgraph/hedera-services/issues/9373
- [ ] #5458
- [ ] #5459
- [ ] #5460
- [ ] #5461
- [ ] #5462
- [ ] https://github.com/hashgraph/hedera-services/issues/7993
- [ ] https://github.com/hashgraph/hedera-services/issues/8146
- [ ] https://github.com/hashgraph/hedera-services/issues/8148
- [ ] https://github.com/hashgraph/hedera-services/issues/8422
- [ ] https://github.com/hashgraph/hedera-services/issues/8786
- [ ] #9000
- [ ] #9001
- [ ] https://github.com/hashgraph/hedera-services/issues/9374
- [ ] https://github.com/hashgraph/hedera-services/issues/9376
- [ ] https://github.com/hashgraph/hedera-services/issues/9375
- [ ] https://github.com/hashgraph/hedera-services/issues/9377
- [ ] #9573
- [ ] https://github.com/hashgraph/hedera-services/issues/9631
- [ ] https://github.com/hashgraph/hedera-services/issues/10910
- [ ] https://github.com/hashgraph/hedera-services/issues/11161
- [ ] https://github.com/hashgraph/hedera-services/issues/11740
- [ ] https://github.com/hashgraph/hedera-services/issues/11741
- [ ] https://github.com/hashgraph/hedera-services/issues/11868
- [ ] https://github.com/hashgraph/hedera-services/issues/11869
- [ ] #11830
- [ ] https://github.com/hashgraph/hedera-services/issues/11925
- [ ] #12337
- [ ] #12015
- [ ] https://github.com/hashgraph/hedera-services/issues/12346
- [ ] https://github.com/hashgraph/hedera-services/issues/12176
- [ ] https://github.com/hashgraph/hedera-services/issues/12226
- [ ] https://github.com/hashgraph/hedera-services/issues/12507
- [ ] https://github.com/hashgraph/hedera-services/issues/12175
- [ ] https://github.com/hashgraph/hedera-services/issues/12637
- [ ] https://github.com/hashgraph/hedera-services/issues/12638
- [ ] https://github.com/hashgraph/hedera-services/issues/12921
- [ ] #13081
- [ ] https://github.com/hashgraph/hedera-services/issues/13548

Start with the platform-sdk/swirlds-logging API linked in the issue and review the proposed DefaultLogEvent shape and logging requirements. The issue does not identify implementation files, tests, or a bounded first deliverable, so the scope and definition of done need to be narrowed before implementation.

Written by the indexing model from the issue text.