Replace custom Logger with slf4j's SocketAppenders and a single logging server

[hubertp]

We currently have a custom logger implementation that is being used in every backend service. The primarily reason for that was that we could collect all logs into a single file.
While the service has worked without any problems, further maintenance and adding new features will be problematic.

1. We would like that add rolling log files, so that customers/cloud do not experience the "out of disk space" problems. Since we have a custom logger implementation, we would have to use something custom as well, rather than off-the-shelf, which is an unnecessary burden.
2. Profiling the startup of Enso reveals that all those individual logging threads created for every sub-service can affect resource usage. Using off-the-shelf appenders, that have been typically optimized, could reduce the problem.
3. Less code to maintain = profit.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-07-27):

Progress: Catching up after a break. Picked up where I left off with logging replacement, updating to latest develop. It should be finished by 2023-07-31.

Next Day: Next day I will be working on the #7253 task. Continue with replacing our custom logging service with something off the shelf.

[Akirathan]

Another advantage of using an off-the-shelf logging library is that the logs have, by default, some standard format which is recognizable by most of the log-viewer software, like lnav for example. Currently, our log files do not have such standard format, we always have to investigate the logs as text-only files.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-07-28):

Progress: Investigating problems related to running basic projects (#7095). Turned out to be a common versioning mismatch between IDE and engine. Continued with replacing our own loggers with something off the shelf. It's pretty tightly integrated so will likely take more time than initially anticipated. It should be finished by 2023-07-31.

Next Day: Next day I will be working on the #7253 task. Continue with refactoring our logging.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-07-31):

Progress: Continue the effort of replacing our custom logging and version mismatch problems for certain users. This will take much longer to implement. It should be finished by 2023-07-31.

Next Day: Next day I will be working on the #7253 task. Continue with refactoring our logging.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for yesterday (2023-08-01):

Summary: There is 4 days delay in implementation of the Replace custom Logger with slf4j's SocketAppenders and a single logging server (#7253) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Existing logging implementation supported more use-cases than I initially anticiapted. Takes time to get through it.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-01):

Progress: Starting to understand the reason for elaborate configuration system. Working towards supporting simple use-cases first. It should be finished by 2023-08-04.

Next Day: Next day I will be working on the #7253 task. Continue with refactoring our logging.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for today (2023-08-03):

Progress: Got simple forwarding working with a simple external socket logging server. Attempting to integrate when initializing individual services. It should be finished by 2023-08-04.

Next Day: Next day I will be working on the #7253 task. Continue with refactoring our logging infra.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-02):

Progress: (Previous status was for 08-02, this one is for 08-03). A simple server now collects logs from individual services and is able to store them in whatever appender we pick (e.g. file appender). Still struggling with getting truffle logger to also send logs to our centralized logger. It should be finished by 2023-08-04.

Next Day: Next day I will be working on the #7253 task. Continue with refactoring our logging infra.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-04):

Progress: (Late submission) Continued with integration of all logs. Finally managed also to accept and forward correctly Truffle logs. It should be finished by 2023-08-04.

Next Day: Next day I will be working on the #7253 task. Prepare PR for review.

[enso-bot]

Paweł Grabarz reports a new 🔴 DELAY for yesterday (2023-08-07):

Summary: There is 6 days delay in implementation of the Replace custom Logger with slf4j's SocketAppenders and a single logging server (#7253) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: More tweaks to logging configuration + slightly reduced hours recently.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-07):

Progress: Preparing PR for review. Adding more tweaks to configure logging to whatever is needed. It should be finished by 2023-08-10.

Next Day: Next day I will be working on the #7253 task. Continue on cleaning up the PR.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-09):

Progress: More cleanups to logging configuration ( reduced hours ). It should be finished by 2023-08-10.

Next Day: Next day I will be working on the #7253 task. Continue on cleaning up the PR and prepare for draft.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-10):

Progress: Draft PR is up, still need to tweak it to add masking of logs and some fallback cases. Overall it seems to be working fine and is (almost) a 1:1 equivalent of what we had. It should be finished by 2023-08-10.

Next Day: Next day I will be working on the #7253 task. Add missing configurations.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2023-08-11):

Summary: There is 5 days delay in implementation of the Replace custom Logger with slf4j's SocketAppenders and a single logging server (#7253) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: I greatly underestimated how much time the task will take and how much I will be able to give it last week.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-11):

Progress: Fixing native image build, fixing tests and providing the small missing bits. It should be finished by 2023-08-15.

Next Day: Next day I will be working on the #7253 task. Finish fixing tests.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-14):

Progress: Struggling with some test setup. Fixing them one by one. It should be finished by 2023-08-15.

Next Day: Next day I will be working on the #7253 task. Continue with launcher tests. Seems to exercise some unknown case.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-15):

Progress: Got all relevant tests to pass. Still not quite there yet with the functionality and not quite happy in how complex the implementation is. Will need another review. It should be finished by 2023-08-15.

Next Day: Next day I will be working on the #7253 task. Looking into simplfying the implementation.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for yesterday (2023-08-16):

Summary: There is 6 days delay in implementation of the Replace custom Logger with slf4j's SocketAppenders and a single logging server (#7253) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Not happy with the complexity of the proposed PR.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-16):

Progress: Not particularly happy with the existing solution which too closely mimicks the existing implementation. Looking into alternatives - talking with Jaroslav about going all in with java util logging but I'm not convinced this is necessary or even possible. Started simplifications but not finished yet. It should be finished by 2023-08-21.

Next Day: Next day I will be working on the #7253 task. Continue with simplification of the implementation.

[hubertp]

One thing to note:

14:08:53.734 [job-pool-1] DEBUG org.enso.interpreter.runtime.DefaultPackageRepository -- Resolving component groups of package [New_Project_16].
14:08:53.891 [job-pool-1] INFO org.enso.interpreter.runtime.DefaultPackageRepository -- Found library Standard.Base @ 0.0.0-dev at [***/0.0.0-dev].

and

14:08:52.289 [scala-execution-context-global-31] DEBUG org.enso.distribution.DistributionManager -- Detected paths: DistributionPaths(
  dataRoot = ***/enso,
  runtimes = ***/runtime,
  engines  = ***/dist,
  bundle   = None,
  config   = ***/enso,
  locks    = ***/lock,
  logs     = ***/log,
  tmp      = ***/tmp,
  ensoHome = ***/enso,
  customEditions = ArraySeq(***/editions),
  localLibrariesSearchpaths = ArraySeq(***/libraries)
)
14:08:52.302 [scala-execution-context-global-31] DEBUG org.enso.distribution.config.GlobalConfigurationManager -- Global config [/home/hubert/.config/enso/global-config.yaml] not found, falling back to defaults.

I thought I broke that with my change but those are coming from the nightly. Notice how they do not respect the format of other logs because they are clearly formatted by the default non-enso loggers.

This is because those messages are logged before logs are setup correctly.

[JaroslavTulach]

they do not respect the format .... those messages are logged before logs are setup correctly.

Usual problem of having uninitialized objects in the system - they are pathological liars.

LogManager offers some properties to allow one to configure everything before first LogRecord is published. Just make sure java.util.logging.config.class points to the class that configures all the log handlers...

[hubertp]

It's not so easy in this case, I'm afraid. That class discovers the root where the log files should be placed (dependent on the distribution) so it's a catch-22.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-17):

Progress: Good progress on simplification. Managed to remove all logback configs and replace them by code. Now reading all logging configs from application.conf again. It should be finished by 2023-08-21.

Next Day: Next day I will be working on the #7253 task. Finish simplicication and update PR.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-18):

Progress: Cleaned up the PR. Shows the simplification I was aiming for. Still some documentation is missing. It should be finished by 2023-08-21.

Next Day: Next day I will be working on the #7253 task. Fill in the missing bits in documentation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2023-08-21):

Progress: More documentation, getting rid of last logback config. It should be finished by 2023-08-21.

Next Day: Next day I will be working on the #7253 task. Documentation and testing

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2023-09-01):

Summary: There is 11 days delay in implementation of the Replace custom Logger with slf4j's SocketAppenders and a single logging server (#7253) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Parked the ticket until PR feedback was gathered and moved on to working on #7017 in the meantime.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-09-01):

Progress: Addressing more logging feedback. Encountered some problems with building native images. Tested extensively with sentry.io It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7698 task. Look into spurious GraalVM downloads

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-08):

Progress: (late submission) Continued refactoring of logging. It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7253 task. Continue the integration.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-22):

Progress: (late submission) Investigating #7624, continued work on logging. It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7253 task. Continue the integration.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-23):

Progress: (late submission) Separating API from implementation via reflection/config loading in logging PR. It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7253 task. Continue the integration.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-24):

Progress: (late submission) Adding documentation and examples, simplfying some implementation. It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7253 task. Continue the integration.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2023-08-25):

Progress: (late submission) More documentation and testing. Preparing for final review. It should be finished by 2023-09-01.

Next Day: Next day I will be working on the #7017 task. Pick up refactoring work.