Page MenuHomePhabricator

Write non-error execution logs to stdout instead of stderr, only surface stderr from child processes in host processes like the scheduler
AbandonedPublic

Authored by dgibson on Sep 24 2020, 7:38 PM.

Details

Summary

The high-level goal here is to make the scheduler process output more legible - right now it surfaces every log from every execution it triggers, which is not very useful if you're just trying to monitor what's going on.

This happens because the scheduler opens user processes to execute scheduled runs, and they are very verbose.

Where I landed for now (Which I'm not positive is right) is to still include anything that was logged to stderr in the scheduler runs, and to change our default logger so that it writes INFO and DEBUG to stdout (It always confused me why we were writing all log output to stderr, although that appears to be the default Python logging behavior). Then only surface STDERR in host processes by default (the gRPC server already does this, but that's because it reads stdout to determine when the server started)

This would also affect console output from Dagit.

Does this seem reasonable? If so I will write some tests.

Test Plan

Pending based on initial feedback

Diff Detail

Repository
R1 dagster
Branch
loggingfuntests
Lint
Lint Errors
Unit
No Unit Test Coverage

Event Timeline

Fix test (to make sense again)

Harbormaster returned this revision to the author for changes because remote builds failed.Sep 24 2020, 8:24 PM
Harbormaster failed remote builds in B18688: Diff 22695!
Harbormaster failed remote builds in B18689: Diff 22696!

A sample of some of the test changes we would need to make, will hold off until it's determined whether we even want to do this

dgibson published this revision for review.Sep 24 2020, 9:05 PM

send cli api stdout to DEVNULL instead of PIPE

A related weird thing that's happening in master now is that when you run dagster pipeline launch in the terminal, you get control back as soon as it launches, but the subprocess that it creates still spews logs to your terminal afterwards.

rebase, fixed more (not all) test failures

alangenfeld added a subscriber: nate.

I think @nate was involved in setting things the way they are and might know more / have opinions

hmm I haven't worked on this part of the system much, but the proposal sounds reasonable; would love to hear from @max and @prha when he's back

I cant think of a reason not to do this - defer this to others

python_modules/dagster/dagster/seven/__init__.py
51–54

comment about why

Hmm, I'm not sure there's a reason for it to go to stderr... but it's been that way forever.

One potential downside is that user context.log calls would get buried amongst the event logs with no easy (unix piping) way to unwind them? But I don't have a real objection to this change.

If we land this, we might want to create a task to switch the compute log viewer UI to show stdout instead of stderr by default.

This revision is now accepted and ready to land.Fri, Oct 16, 2:20 PM

I'm going to hold off on this for now, will keep it in the back pocket though