Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AGENT-336 Add ability to log to stdout/stderr #415

Merged
merged 10 commits into from
Mar 4, 2020
Merged

AGENT-336 Add ability to log to stdout/stderr #415

merged 10 commits into from
Mar 4, 2020

Conversation

yanscalyr
Copy link
Contributor

New optional parameters force_stdout and force_stderr. force_stdout won't do anything if we are already set to log to stdout.

Currently I wrote this by having the loggers add and remove relevant handlers during logging, they are being attached to the actual logger that is being called, and not the one the message eventually propagates to so I don't think there should be any threading issues related to this.

@codecov
Copy link

codecov bot commented Feb 18, 2020

Codecov Report

Merging #415 into master will increase coverage by 0.07%.
The diff coverage is n/a.

Impacted file tree graph

@@            Coverage Diff             @@
##           master     #415      +/-   ##
==========================================
+ Coverage   76.44%   76.51%   +0.07%     
==========================================
  Files         104      104              
  Lines       26734    26823      +89     
==========================================
+ Hits        20436    20524      +88     
- Misses       6298     6299       +1     
Impacted Files Coverage Δ
scalyr_agent/run_monitor.py 57.14% <0.00%> (-1.30%) ⬇️
...calyr_agent/builtin_monitors/kubernetes_monitor.py 70.25% <0.00%> (-0.15%) ⬇️
scalyr_agent/profiler.py 67.94% <0.00%> (ø)
.../builtin_monitors/tests/kubernetes_monitor_test.py 97.68% <0.00%> (ø)
scalyr_agent/scalyr_logging.py 86.30% <0.00%> (+1.11%) ⬆️
...calyr_agent/monitor_utils/blocking_rate_limiter.py 94.75% <0.00%> (+0.40%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 9d85a4b...1e511c9. Read the comment docs.

Copy link
Contributor

@czerwingithub czerwingithub left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm advocating a design that's more consistent with how we are already doing similar things. It does mean a little extra coding but I think it's better to be consistent in this case.

stdout_handler = self.__stdout_handler
stderr_handler = self.__stderr_handler

if force_stdout and stdout_handler:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Rather than adding and removing this handler for each emit, we should just re-use the __thread_local__ pattern here. We should have __thread_local__.last_force_stdout and __thread_local__.last_force_stderr that get set here. Then, use that in makeRecord to set attributes force_stdout and force_stderr on the returned record. Finally, add a filter to the stdout and stderr handlers such that they are only used if the record they are asked to handle has force_stdout or force_stderr set to True.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That would cover any possible race conditions too (I don't think there are any but better safe than sorry), sounds good to me.

@Kami
Copy link
Contributor

Kami commented Feb 19, 2020

It looks like if force_stdout/stderr variable is set, we still log to the files (in addition to stdout / stderr), right?

Would it make sense to log only to stdout / stder in such scenario (perhaps as an option, because I know this will affect agent.log and agent_debug.log files which won't be shipped to Scalyr in that scenario).

On a related note, I think we should enable logging to stdout / stderr by default when running in foreground mode (--no-fork flag). That's the default behavior for most applications when running in foreground / non-daemon mode.

@@ -371,6 +371,20 @@ def test_force_valid_metric_or_field_name(self):
fixed_name2 = scalyr_logging.AgentLogger.force_valid_metric_or_field_name(name2)
self.assertEqual(fixed_name2, name2)

def test_output_to_file_with_stdout(self):
self.__logger.info("Hello world", force_stdout=True)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It would be good to assert that the message is also output to stdout (in addition to the file).

For that, we will likely need to patch sys.stdout and sys.stderr.

@yanscalyr
Copy link
Contributor Author

It looks like if force_stdout/stderr variable is set, we still log to the files (in addition to stdout / stderr), right?

Would it make sense to log only to stdout / stder in such scenario (perhaps as an option, because I know this will affect agent.log and agent_debug.log files which won't be shipped to Scalyr in that scenario).

On a related note, I think we should enable logging to stdout / stderr by default when running in foreground mode (--no-fork flag). That's the default behavior for most applications when running in foreground / non-daemon mode.

The intent was to log to stdout/stderr in addition to the usual log paths yes. I don't know of a case where we wouldn't want to send the logs up to Scalyr so I'm not sure how useful a stdout only option would be, maybe @czerwingithub has some insight?

Regarding --no-fork, that is how we run in k8s and I believe the point of this was to log things that would be interesting to see when inspecting the pod, if we log everything like this it would show one random log line. Though I do agree that it makes sense for every other case, maybe some k8s specific flag would be in order?

@Kami
Copy link
Contributor

Kami commented Feb 20, 2020

The intent was to log to stdout/stderr in addition to the usual log paths yes. I don't know of a case where we wouldn't want to send the logs up to Scalyr so I'm not sure how useful a stdout only option would be, maybe @czerwingithub has some insight?

Yeah, I'm fine with also logging to the log files in addition to stdout/stderr to not break agent.log + agent_debug.log upload functionality.

Regarding --no-fork, that is how we run in k8s and I believe the point of this was to log things that would be interesting to see when inspecting the pod, if we log everything like this it would show one random log line. Though I do agree that it makes sense for every other case, maybe some k8s specific flag would be in order?

I'm fine with a separate flag for k8s / docker deployment. This would offer us more flexibility in the future as well - instead of us trying to programatically detect if we are running inside a container / on Kubernetes we can just rely on a presence of that flag.

@return: True if the record should be logged by this handler.
@rtype: bool
"""
return hasattr(record, "force_stdout") and record.force_stdout
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Minor style thing, could also just use getattr aka return getattr(record, "force_stdout", False).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The hasattr approach matches how its used in the other filters, would it be worth changing all of the uses do you think?

stdout_bkp = sys.stdout.write
sys.stdout.write = types.MethodType(self.fake_std_write, sys.stdout)
try:
self.__logger.info("Hello world", force_stdout=True)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It probably also wouldn't hurt to add a test case for negative / default scenario when force arguments are False.

@czerwingithub
Copy link
Contributor

czerwingithub commented Mar 3, 2020 via email

@yanscalyr yanscalyr merged commit fc1fb15 into master Mar 4, 2020
@yanscalyr yanscalyr deleted the log_to_std branch March 4, 2020 23:01
@Kami Kami mentioned this pull request Mar 16, 2020
1 task
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants