RHCLOUD-4283 - Enabling stdout logs #650

tahmidefaz · 2020-04-30T18:39:27Z

No description provided.

tahmidefaz · 2020-04-30T18:44:31Z

Is this solution any good? Tried hard not to use global variables. If you can think of a more elegant solution, let me know.
You can check out the platform-dev log group's test_logs_inv stream on cloudwatch to check out the test logs I produced (towards the end).

shdunning

questions and a simple re-write suggestion

app/logging.py

tahmidefaz · 2020-05-04T15:49:10Z

@jharting just set the env var to use logconfig.ini as default. 👍

ryandillinfelton

LGTM

Glutexo

I don’t understand how this enables output to stdout. It only changes the way how stuff is logged to CloudWatch. Originally we relied on propagating our logs to the root logger, now we use the CloudWatch handler in every logger. I don’t think this approach is any better.

If using the CloudWatch handler for the root logger is not desired, then we can at least configure it for the inventory handler. That handler is a parent of all loggers returned by get_logger and if not overridden by the INI file log configuration, all logs are propagated automatically to it.

In this review I focused only on replacing the global Boto3 session with a global handler. Handlers are naturally reused and here, the configuration is the same for every logger.

app/logging.py

Glutexo · 2020-05-11T12:28:48Z

Okay. Hopefully found a way how to do it.

Glutexo

Instead of configuring each handler separately in the get_logger function, configure the inventory handler only once.
- Instantiate it in the configure_logging function, set the log level.
- Pass it to the contextual filter and Watchtower configuration functions.
In the watchtower configuration function, read the configuration data and if present, create a handler and add it to the logger.
Simplify the get_logger function so it only returns a child logger inventory.*. It propagates to the inventory one that has the CloudWatch handler and contextual filter.
Remove all the garbage from logconfig.ini, keep only root and library configuration.
- All the inventory modules (app, lib etc.) should go away.
- Add inventory with some basic configuration like loglevel=INFO etc. so it’s properly logged to stdout.

app/logging.py

Glutexo · 2020-05-11T12:35:29Z

app/logging.py

+        global session_boto3
+        session_boto3 = boto3_session


Suggested change

global session_boto3

session_boto3 = boto3_session

handler = _get_cloudwatch_handler(aws_access_key_id, aws_secret_access_key, aws_region_name, aws_log_group, aws_stream_name, create_log_group)

logger = logging.addHandler(handler)

see my comment below

app/logging.py

Glutexo · 2020-05-22T11:28:49Z

There is now a conflict, caused by my #657 being merged in. It shouldn’t affect your code though.

tahmidefaz · 2020-05-27T20:20:19Z

@Glutexo I think I took your suggestions into account, but sadly it does not send any logs to cloudwatch. I will keep digging, but let me know if you see something I did that diverges from the changes you suggested.

tahmidefaz · 2020-05-27T20:26:04Z

Also, regarding changing logconfig.ini did you meant taking out app, api, tasks, mq_service, lib, utils out? and replace it with only one logger_inventory with qualname=inventory? @Glutexo

tahmidefaz · 2020-05-28T21:11:35Z

Ok, fixed it. 😓
We def need that global cloudwatch_handler, didn't find a way to make it work without it. This solution diverges slightly from @Glutexo 's proposal. Lmk, if there are any concerns.

shdunning

just a qq.

app/logging.py

shdunning

this one lgtm!

tahmidefaz · 2020-07-02T12:39:47Z

Oops! Didn't realize that was causing the issue 😞

tahmidefaz · 2020-07-02T15:27:24Z

@Glutexo In configure_logging(), we can just check whether the cloudwatch credentials were provided, and if not we can simply remove that info from the dictionary before loading it via dictConfig. What do you think?

tahmidefaz · 2020-07-02T16:10:36Z

^ This simply removes the cloudwatch handler info from the dictionary if creds aren't present. Let me know if you can think of a better way to do this.

Glutexo · 2020-07-02T16:58:01Z

@tahmidefaz What’s wrong with the NullHandler? 😦 Now when we now we need to return an instance instead of a class.

tahmidefaz · 2020-07-02T17:31:33Z

@Glutexo sorry, I misunderstood. I will revert 🤦‍♂️

…ost-inventory into stdout-logging

Makefile

Glutexo · 2020-07-02T16:38:50Z

Makefile


 run_inv_mq_service:
-	PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.ini \
+	PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.yaml \


Here again, the INVENTORY_LOGGING_CONFIG_FILE is not needed.

Glutexo · 2020-07-02T16:45:17Z

app/__init__.py

@@ -40,6 +38,7 @@ def create_app(runtime_environment):
    # This feels like a hack but it is needed.  The logging configuration
    # needs to be setup before the flask app is initialized.
    configure_logging(runtime_environment)
+    logger = get_logger(__name__)  # we need to call the logger after configuring it, not before


Is the comment actually true? Even if we get the logger before the configuration, its configuration still gets updated. It makes perfect sense to get the logger after the configuration, but technically it’s not necessary.

Suggested change

logger = get_logger(__name__) # we need to call the logger after configuring it, not before

logger = get_logger(__name__)

To reproduce, swap these two lines and see the logging still works the same. Compare to how it doesn’t work if you try to log something before the configuration.

I believe the reason I moved this line around was that due to the way logging was setup earlier, some of the logs weren't being produced. However, after the logging refactoring, that seems to be fixed. I will move it back to where it was earlier. 👍

app/logging.py

Glutexo · 2020-07-02T18:11:19Z

app/logging.py

    else:
        print("Unable to configure watchtower logging.  Please verify watchtower logging configuration!")
+        return NullHandler()


logconfig.ini

logconfig.yaml

Glutexo · 2020-07-02T18:14:45Z

run_gunicorn.py

@@ -30,7 +30,7 @@ def run_server():
    variables.
    """
    bind = f"0.0.0.0:{LISTEN_PORT}"
-    run(("gunicorn", "--log-config=logconfig.ini", "--log-level=debug", f"--bind={bind}", "run"))
+    run(("gunicorn", "--log-config=logconfig.yaml", "--log-level=debug", f"--bind={bind}", "run"))


Does this actually work? Not only I am afraid that it doesn’t but we also found out that it’s this loading the configuration by the --log-config argument that causes problems. Let’s remove it instead.

Suggested change

run(("gunicorn", "--log-config=logconfig.yaml", "--log-level=debug", f"--bind={bind}", "run"))

run(("gunicorn", "--log-level=debug", f"--bind={bind}", "run"))

Confirmed. It tries to use the configparser.

configparser.MissingSectionHeaderError: File contains no section headers. file: 'logconfig.yaml', line: 1 '---\n'

This may be a solution. We already use gunicorn.conf.py in production. I think we can move the logging configuration there! Not in this PR, but it’d definitely worth exploring.

Glutexo · 2020-07-02T18:16:04Z

@tahmidefaz It looks like you already fixed most of my comments. We’re getting there!

tahmidefaz · 2020-07-02T18:23:17Z

@Glutexo sorry for the hiccup earlier, today is a day of major faceplams 🤦‍♂️
I did a revert to where things were in your branch and added the NullHandler(). I also removed the logconfig.ini file. I am going to address the other concerns you have.
I will also need to open a subsequent PR in e2e-deploy to incorporate the new logconfig.yaml.

Glutexo · 2020-07-02T18:26:24Z

@tahmidefaz Do you know what needs to be done there and how? Can you post a link here once you have it?

tahmidefaz · 2020-07-02T18:30:05Z

@Glutexo yes, I will mention this PR in e2e-deploy once I get around to it

tahmidefaz · 2020-07-02T19:22:35Z

^ @Glutexo I think in terms of the changes in e2e-deploy, that should be good. Please take a look.

Removed CloudWatch configuration status logging. It doesn’t work correctly and moreover duplicates existing print statements.

Value of INVENTORY_LOGGING_CONFIG_FILE in the Makefile only fills in the default value. That is redundant and thus removed.

Glutexo

Found some minor issues. Fixing and pushing them right away.

I can finally confirm this works. 🎉 Logging both to standard output and to CloudWatch works. There are no nasty globals or configuration shenanigans. Without CloudWatch credentials, messages are logged only to standard output.

There is only one sad thing. Now, when the runtime environment flag is not used when loading the logging configuration, the Flask app tries to configure the CloudWatch handler in tests too. Because there are no credential provided in the tests, this only results in a message being printed. But this should be addressed in the future somehow.

Glutexo · 2020-07-03T07:31:52Z

Makefile


 run_inv_mq_service:
-	PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.ini \
+	PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.yaml \


Here again, the INVENTORY_LOGGING_CONFIG_FILE is not needed.

Glutexo · 2020-07-03T07:32:29Z

Makefile

+	PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.yaml \
 	INVENTORY_LOG_LEVEL=DEBUG python inv_mq_service.py


Suggested change

PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.yaml \

INVENTORY_LOG_LEVEL=DEBUG python inv_mq_service.py

PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOG_LEVEL=DEBUG python inv_mq_service.py

Glutexo · 2020-07-03T08:00:35Z

app/logging.py

+        aws_log_group = os.getenv("AWS_LOG_GROUP", "platform")
+        aws_log_stream = os.getenv("AWS_LOG_STREAM", _get_hostname())
+        create_log_group = str(os.getenv("AWS_CREATE_LOG_GROUP")).lower() == "true"
+        logger.info(f"Configuring watchtower logging (log_group={aws_log_group}, stream_name={aws_log_stream})")


Suggested change

logger.info(f"Configuring watchtower logging (log_group={aws_log_group}, stream_name={aws_log_stream})")

Glutexo · 2020-07-03T08:00:45Z

app/logging.py


-    if all([aws_access_key_id, aws_secret_access_key, aws_region_name, stream_name]):
-        print(f"Configuring watchtower logging (log_group={log_group}, stream_name={stream_name})")
+    logger = get_logger(__name__)


Suggested change

logger = get_logger(__name__)

Glutexo · 2020-07-03T09:45:16Z

Tests passed. @jharting, are you okay with merging?

tahmidefaz requested review from jharting, Glutexo and ryandillinfelton April 30, 2020 18:39

tahmidefaz requested a review from shdunning as a code owner April 30, 2020 18:39

shdunning suggested changes May 1, 2020

View reviewed changes

app/logging.py Show resolved Hide resolved

app/logging.py Outdated Show resolved Hide resolved

tahmidefaz force-pushed the stdout-logging branch from 5f304db to def379d Compare May 1, 2020 19:26

rebasing

f150695

tahmidefaz force-pushed the stdout-logging branch from def379d to f150695 Compare May 1, 2020 19:33

tahmidefaz requested a review from shdunning May 1, 2020 19:48

tahmidefaz added 2 commits May 4, 2020 11:47

using logconfig as default log_config_file

4d83a84

Merge branch 'master' into stdout-logging

f4d5bc2

ryandillinfelton approved these changes May 4, 2020

View reviewed changes

Glutexo requested changes May 11, 2020

View reviewed changes

app/logging.py Outdated Show resolved Hide resolved

app/logging.py Outdated Show resolved Hide resolved

app/logging.py Outdated Show resolved Hide resolved

app/logging.py Outdated Show resolved Hide resolved

app/logging.py Outdated Show resolved Hide resolved

Glutexo reviewed May 11, 2020

View reviewed changes

tahmidefaz added 3 commits May 22, 2020 08:30

Merge remote-tracking branch 'origin' into stdout-logging

afca122

resolving conflicts

c983e0c

applying suggestions

e693f88

fixing cloudwatch logs

8e61d98

Glutexo assigned tahmidefaz Jun 1, 2020

tahmidefaz requested a review from Glutexo June 3, 2020 12:38

Merge branch 'master' into stdout-logging

188767e

shdunning reviewed Jun 4, 2020

View reviewed changes

app/logging.py Outdated Show resolved Hide resolved

shdunning approved these changes Jun 9, 2020

View reviewed changes

remove cw handler if creds not present

adc7f91

freaking lint 🤦‍♂️

6a0bd5b

tahmidefaz added 6 commits July 2, 2020 13:47

reverting

4dee8cb

reverting

c7bda5e

fix

36895ea

Merge branch 'master' into stdout-logging

060c8a5

deleting logconfig.ini

68dd40a

Merge branch 'stdout-logging' of github.com:RedHatInsights/insights-h…

a824ae5

…ost-inventory into stdout-logging

Glutexo requested changes Jul 2, 2020

View reviewed changes

addressing suggestions

213a10e

Glutexo added 2 commits July 3, 2020 10:07

Remove redundant logging

270d3fe

Removed CloudWatch configuration status logging. It doesn’t work correctly and moreover duplicates existing print statements.

Remove config file variable from Makefile

9628b91

Value of INVENTORY_LOGGING_CONFIG_FILE in the Makefile only fills in the default value. That is redundant and thus removed.

Glutexo requested changes Jul 3, 2020

View reviewed changes

Glutexo approved these changes Jul 3, 2020

View reviewed changes

Glutexo mentioned this pull request Jul 3, 2020

Tests refactor #655

Merged

5 tasks

update README

8ad446c

jharting approved these changes Jul 7, 2020

View reviewed changes

jharting merged commit f7e099a into master Jul 7, 2020

Glutexo deleted the stdout-logging branch July 13, 2020 09:54

	logger = get_logger(__name__) # we need to call the logger after configuring it, not before
	logger = get_logger(__name__)

	run(("gunicorn", "--log-config=logconfig.yaml", "--log-level=debug", f"--bind={bind}", "run"))
	run(("gunicorn", "--log-level=debug", f"--bind={bind}", "run"))

		PAYLOAD_TRACKER_SERVICE_NAME=inventory-mq-service INVENTORY_LOGGING_CONFIG_FILE=logconfig.yaml \
		INVENTORY_LOG_LEVEL=DEBUG python inv_mq_service.py

RHCLOUD-4283 - Enabling stdout logs #650

RHCLOUD-4283 - Enabling stdout logs #650

Conversation

tahmidefaz commented Apr 30, 2020

tahmidefaz commented Apr 30, 2020 • edited

shdunning left a comment

Choose a reason for hiding this comment

tahmidefaz commented May 4, 2020

ryandillinfelton left a comment

Choose a reason for hiding this comment

Glutexo left a comment

Choose a reason for hiding this comment

Glutexo commented May 11, 2020

Glutexo left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Glutexo commented May 22, 2020

tahmidefaz commented May 27, 2020

tahmidefaz commented May 27, 2020

tahmidefaz commented May 28, 2020

shdunning left a comment

Choose a reason for hiding this comment

shdunning left a comment

Choose a reason for hiding this comment

tahmidefaz commented Jul 2, 2020

tahmidefaz commented Jul 2, 2020

tahmidefaz commented Jul 2, 2020

Glutexo commented Jul 2, 2020

tahmidefaz commented Jul 2, 2020

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

Choose a reason for hiding this comment

Glutexo commented Jul 2, 2020 • edited

tahmidefaz commented Jul 2, 2020

Glutexo commented Jul 2, 2020

tahmidefaz commented Jul 2, 2020

tahmidefaz commented Jul 2, 2020 • edited

Glutexo 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

Glutexo commented Jul 3, 2020

tahmidefaz commented Apr 30, 2020 •

edited

Glutexo commented Jul 2, 2020 •

edited

tahmidefaz commented Jul 2, 2020 •

edited