add logger messages to activation-worker log #1235

ShaiahWren · 2025-03-11T19:26:50Z

Ensure error and info logs are written to the activation-worker logs, as well as the DB/UI logs.
AAP-41782

codecov-commenter · 2025-03-11T19:35:25Z

Codecov Report

Attention: Patch coverage is 78.00000% with 11 lines in your changes missing coverage. Please review.

Project coverage is 93.88%. Comparing base (c15d2b9) to head (e1f9672).

Files with missing lines	Patch %	Lines
.../aap_eda/services/activation/activation_manager.py	60.00%	4 Missing ⚠️
src/aap_eda/services/activation/tee_log_handler.py	87.09%	4 Missing ⚠️
src/aap_eda/settings/post_load.py	66.66%	3 Missing ⚠️

@@            Coverage Diff             @@
##             main    #1235      +/-   ##
==========================================
- Coverage   93.90%   93.88%   -0.03%     
==========================================
  Files         290      291       +1     
  Lines       16123    16161      +38     
==========================================
+ Hits        15141    15172      +31     
- Misses        982      989       +7

Flag	Coverage Δ
unit-int-tests-3.11	`93.81% <78.00%> (-0.03%)`	⬇️
unit-int-tests-3.12	`93.88% <78.00%> (-0.03%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines	Coverage Δ
src/aap_eda/settings/post_load.py	`94.35% <66.66%> (-1.54%)`	⬇️
.../aap_eda/services/activation/activation_manager.py	`63.29% <60.00%> (ø)`
src/aap_eda/services/activation/tee_log_handler.py	`87.09% <87.09%> (ø)`

🚀 New features to boost your workflow:

❄ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

hsong-rh · 2025-03-11T19:41:13Z

src/aap_eda/services/activation/engine/podman.py

+
+                    if "ERROR" in message:
+                        LOGGER.error(message)
+                    else:


we should also check for WARN, DEBUG, FATAL, and DEBUG. It's not good to log them as INFO level.

hsong-rh · 2025-03-11T19:43:22Z

@ShaiahWren Can you add a pytest for it?

Alex-Izquierdo

Can you add a test?

Alex-Izquierdo · 2025-03-12T19:35:37Z

src/aap_eda/services/activation/tee_log_handler.py

+LOGGER = logging.getLogger(__name__)
+
+
+class TeeLogger(DBLogger):


Can you add a docstring clarifying the purpose of the class? Maybe use a more self descriptive name like "TeeSystemLogger" too ?

Alex-Izquierdo · 2025-03-12T19:39:50Z

src/aap_eda/services/activation/tee_log_handler.py

+
+
+class TeeLogger(DBLogger):
+    def __init__(self, activation_instance_id: int):


If you don't need to override or extend the initialization of the object there is no need to define __init__ here

BUT, using the LOGGER of this module probably is wrong since all the records would be tracked by this logger and we would be losing the track of the real module that is calling it.

Instead I think it is better to pass the logger in the constructor in a more dependency injector pattern and allow to be used by different implementers, We consume the DBLogger from the engines and from the manager but this new logger I guess is intent to be called only from the engine.

thoughts @hsong-rh @ShaiahWren

I think you are right @Alex-Izquierdo . I'm updating the pr now, and then I'll work on the test.

Are you going to implement this new logger in this PR or in a separate PR?

I will implement it in this pr, if that's alright with you. I also need to write the test this afternoon.

mkanoor · 2025-03-16T07:52:15Z

src/aap_eda/services/activation/tee_log_handler.py

+            else:
+                log_level = logging.INFO
+
+            self.logger.log(log_level, line)


We need to pass in the date times from ansible rulebook
We need to define a formatter for the TeeLogger which has a placeholder for rulebook_timestamp and we can pass that thru using extra args in the log call. The log format should align with the other formatters we have for activation worker but swap out the asctime with the rulebook_timestamp

A sample would look something like this

import logging

this would all be done in settings/post_load.py

the format should align with the rest of our formatters please check with @hsong-rh for more details

Configure logging

logging.basicConfig(
level=logging.INFO,
format='%(rulebook_timestamp)s - %(levelname)s - %(message)s'
)

Create a logger in the teesystemlogger file

logger = logging.getLogger(name)

Log a message with extra parameters

extra_data = {'rulebook_timestamp': 'convert log_timestamp to asctime format in UTC'}

logger.log(log_level,'container id in', extra=extra_data)

I am doing this from the phone so I apologize for any typos

Also in the settings/post_load.py we need to add a settings for the TeeSystemLogger which might look something like this

"aap_eda.services.activation.tee_log_handler": {
"handlers": ["teeloggerhandler"],

the log level should always be DEBUG here since it's controlled by the activation ui screen please don't set this to the default app log level like other settings. This is purely controlled by the user running the activation they might run it with any of the three log levels DEBUG INFO or ERROR and we need to pick the lowest of these 3 for our default

"level": logging.DEBUG, "propagate": False, },

We need to add there as well a field for the rulebook process id, we can not have in the log all those records without the rulebook process context.

@mkanoor do you want to replace the existing timestamp or add new one from the rulebook one?

@Alex-Izquierdo we need to preserve the timestamp from ansible-rulebook and it is present in the log_timestamp argument being passed into this function we can use that except we need to convert it to the asctime format to be consistent. The log_timestamp is in UTC and like other log lines it should get displayed in utc in our logs. This is for our debugging and support engineers coming via SOS reports the user's are not going to see it directly. We can't have 2 time stamps in the log lines it skews the visual perspective as we are debugging. In the formatter we remove the asctime with rulebook_timestamp and pass that in as extra args

mkanoor · 2025-03-16T11:52:42Z

src/aap_eda/services/activation/tee_log_handler.py

@@ -0,0 +1,60 @@
+#  Copyright 2023 Red Hat, Inc.


mkanoor · 2025-03-16T11:59:31Z

src/aap_eda/services/activation/tee_log_handler.py

+
+    def __init__(self, activation_instance_id: int, logger: logging.Logger):
+        super().__init__(activation_instance_id)
+        self.logger = logger


I think the logger should be retrieved from the file name using
'''
import logging
LOGGER = logging.getLogger(name)
'''
This allows us to make custom settings just for this file

Alex-Izquierdo · 2025-03-21T13:49:17Z

src/aap_eda/services/activation/tee_log_handler.py

+                log_level = logging.INFO
+
+            extra_data = {"rulebook_timestamp": rulebook_timestamp}
+            LOGGER.log(log_level, f"{self.prefix} {line}", extra=extra_data)


if you are going to create a teelogger formater, the prefix should be part of the format

Alex-Izquierdo · 2025-03-21T14:08:22Z

src/aap_eda/settings/post_load.py

+    logging.basicConfig(level=logging.DEBUG, format=log_format)
+
+
+def get_logging_settings():


how you will use this function?

Alex-Izquierdo · 2025-03-21T14:41:51Z

src/aap_eda/services/activation/activation_manager.py

@@ -203,7 +203,9 @@ def _start_activation_instance(self):
        self._create_activation_instance()

        self.db_instance.refresh_from_db()
-        log_handler = self.container_logger_class(self.latest_instance.id)
+        log_handler = self.container_logger_class(
+            self.latest_instance.id, LOGGER


Either, with a logger instance or a logger name, now we have two arguments for the constructor and one of them is the same in all the calls, only activation_instance_id is dynamic. There is no need no repeat the same argument in all the calls, you can be more concise with a factory

def get_log_handler(self, activation_instance_id, logger=LOGGER): return self.container_logger_class(activation_instance_id, LOGGER)

So the lines like:

log_handler = self.container_logger_class(self.latest_instance.id)

become

log_handler = self.get_log_handler(self.latest_instance.id)

sonarqubecloud · 2025-03-26T20:26:09Z

Quality Gate passed

Issues
0 New issues
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarQube Cloud

ShaiahWren · 2025-03-31T15:49:09Z

Closing the pr and replacing with #1253

ShaiahWren requested a review from a team as a code owner March 11, 2025 19:26

ShaiahWren requested a review from hsong-rh March 11, 2025 19:27

hsong-rh reviewed Mar 11, 2025

View reviewed changes

ShaiahWren force-pushed the add-logger-messages branch 2 times, most recently from ad329df to 0aff4a1 Compare March 12, 2025 16:38

Alex-Izquierdo reviewed Mar 12, 2025

View reviewed changes

ShaiahWren force-pushed the add-logger-messages branch 2 times, most recently from a37bb19 to e33b011 Compare March 13, 2025 19:08

mkanoor reviewed Mar 16, 2025

View reviewed changes

ShaiahWren force-pushed the add-logger-messages branch 2 times, most recently from 69c2e10 to e1f9672 Compare March 19, 2025 20:28

Alex-Izquierdo reviewed Mar 21, 2025

View reviewed changes

ShaiahWren force-pushed the add-logger-messages branch from e1f9672 to f4b353f Compare March 26, 2025 15:58

add logger messages to activation-worker log

eca9439

ShaiahWren force-pushed the add-logger-messages branch from f4b353f to eca9439 Compare March 26, 2025 20:25

ShaiahWren closed this Mar 31, 2025

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

add logger messages to activation-worker log #1235

add logger messages to activation-worker log #1235

ShaiahWren commented Mar 11, 2025

codecov-commenter commented Mar 11, 2025 •

edited

Loading

hsong-rh Mar 11, 2025

hsong-rh commented Mar 11, 2025

Alex-Izquierdo left a comment

Alex-Izquierdo Mar 12, 2025

Alex-Izquierdo Mar 12, 2025

ShaiahWren Mar 13, 2025

Alex-Izquierdo Mar 13, 2025

ShaiahWren Mar 13, 2025

mkanoor Mar 16, 2025 •

edited

Loading

Alex-Izquierdo Mar 17, 2025

Alex-Izquierdo Mar 17, 2025

mkanoor Mar 18, 2025 •

edited

Loading

Alex-Izquierdo Mar 18, 2025

mkanoor Mar 16, 2025

mkanoor Mar 16, 2025

Alex-Izquierdo Mar 21, 2025

Alex-Izquierdo Mar 21, 2025

Alex-Izquierdo Mar 21, 2025

sonarqubecloud bot commented Mar 26, 2025

ShaiahWren commented Mar 31, 2025

		LOGGER = logging.getLogger(__name__)


		class TeeLogger(DBLogger):



		class TeeLogger(DBLogger):
		def __init__(self, activation_instance_id: int):

		logging.basicConfig(level=logging.DEBUG, format=log_format)


		def get_logging_settings():

add logger messages to activation-worker log #1235

add logger messages to activation-worker log #1235

Conversation

ShaiahWren commented Mar 11, 2025

codecov-commenter commented Mar 11, 2025 • edited Loading

Codecov Report

Choose a reason for hiding this comment

hsong-rh commented Mar 11, 2025

Alex-Izquierdo left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mkanoor Mar 16, 2025 • edited Loading

Choose a reason for hiding this comment

this would all be done in settings/post_load.py

the format should align with the rest of our formatters please check with @hsong-rh for more details

Configure logging

Create a logger in the teesystemlogger file

Log a message with extra parameters

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mkanoor Mar 18, 2025 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sonarqubecloud bot commented Mar 26, 2025

Quality Gate passed

ShaiahWren commented Mar 31, 2025

codecov-commenter commented Mar 11, 2025 •

edited

Loading

mkanoor Mar 16, 2025 •

edited

Loading

mkanoor Mar 18, 2025 •

edited

Loading