Add logging of stdout to dbt graph run_command.

[KarolGongola]

Description

Currently run_command functions put only stderr or stdout into logger. Which is misleading, because there are also important information in stdout even if something exists in stderr.

Related Issue(s)

closes #1356

Breaking Change?

NO

Checklist

• I have made corresponding changes to the documentation (if required)
• I have added tests that prove my fix is effective or that my feature works

[tatiana]

Hi @KarolGongola, thank you very much for improving the logs

I'm happy with the improvement. Could you please fix the tests so they pass? It will also help us avoid any regressions in your log improvement.

Apparently, the following tests broke due to this change:

FAILED tests/dbt/test_graph.py::test_load_via_dbt_ls_with_non_zero_returncode - AssertionError: Regex pattern did not match.
 Regex: "Unable to run \\['.+dbt', 'deps', .*\\] due to the error:\\nSome stderr message"
 Input: "Unable to run ['/home/runner/.local/share/hatch/env/virtual/astronomer-cosmos/Za_bFbg4/tests.py3.11-2.9/bin/dbt', 'deps', '--project-dir', '/tmp/tmpivws28dg', '--profiles-dir', '/tmp/cosmos/profile/d426ea9bd2fe96408d8d2c4f150ab19011d7d7314fc17f613b902308e66fb2e7', '--profile', 'default', '--target', 'default'] due to the error:\nstderr: Some stderr message\nstdout: "
FAILED tests/dbt/test_graph.py::test_load_via_dbt_ls_with_runtime_error_in_stdout - AssertionError: Regex pattern did not match.
 Regex: "Unable to run \\['.+dbt', 'deps', .*\\] due to the error:\\nSome Runtime Error"
 Input: "Unable to run ['/home/runner/.local/share/hatch/env/virtual/astronomer-cosmos/Za_bFbg4/tests.py3.11-2.9/bin/dbt', 'deps', '--project-dir', '/tmp/tmp_jnwrslr', '--profiles-dir', '/tmp/cosmos/profile/d426ea9bd2fe96408d8d2c4f150ab19011d7d7314fc17f613b902308e66fb2e7', '--profile', 'default', '--target', 'default'] due to the error:\nstderr: \nstdout: Some Runtime Error"
= 2 failed, 66 passed, 5 skipped, 667 deselected, 2 warnings in 342.06s (0:05:42) =

[fjmacagno]

I wonder a little if it would be better to not split out the stderr and stdout in the first place, since it could be confusing. Still a substantial improvement.

[KarolGongola]

Hi @KarolGongola, thank you very much for improving the logs

I'm happy with the improvement. Could you please fix the tests so they pass? It will also help us avoid any regressions in your log improvement.

Apparently, the following tests broke due to this change:

FAILED tests/dbt/test_graph.py::test_load_via_dbt_ls_with_non_zero_returncode - AssertionError: Regex pattern did not match.
 Regex: "Unable to run \\['.+dbt', 'deps', .*\\] due to the error:\\nSome stderr message"
 Input: "Unable to run ['/home/runner/.local/share/hatch/env/virtual/astronomer-cosmos/Za_bFbg4/tests.py3.11-2.9/bin/dbt', 'deps', '--project-dir', '/tmp/tmpivws28dg', '--profiles-dir', '/tmp/cosmos/profile/d426ea9bd2fe96408d8d2c4f150ab19011d7d7314fc17f613b902308e66fb2e7', '--profile', 'default', '--target', 'default'] due to the error:\nstderr: Some stderr message\nstdout: "
FAILED tests/dbt/test_graph.py::test_load_via_dbt_ls_with_runtime_error_in_stdout - AssertionError: Regex pattern did not match.
 Regex: "Unable to run \\['.+dbt', 'deps', .*\\] due to the error:\\nSome Runtime Error"
 Input: "Unable to run ['/home/runner/.local/share/hatch/env/virtual/astronomer-cosmos/Za_bFbg4/tests.py3.11-2.9/bin/dbt', 'deps', '--project-dir', '/tmp/tmp_jnwrslr', '--profiles-dir', '/tmp/cosmos/profile/d426ea9bd2fe96408d8d2c4f150ab19011d7d7314fc17f613b902308e66fb2e7', '--profile', 'default', '--target', 'default'] due to the error:\nstderr: \nstdout: Some Runtime Error"
= 2 failed, 66 passed, 5 skipped, 667 deselected, 2 warnings in 342.06s (0:05:42) =

sure, sorry for inconvenience

[KarolGongola]

I wonder a little if it would be better to not split out the stderr and stdout in the first place, since it could be confusing. Still a substantial improvement.

I think that just concatenating them without any info, could be even more misleading, because messages wont be in chronological order.

[KarolGongola]

@tatiana Is it fine now?

[fjmacagno]

I meant keep them in chronological order by using the stderr=STDOUT param. https://docs.python.org/3/library/subprocess.html#subprocess.STDOUT

[KarolGongola]

I meant keep them in chronological order by using the stderr=STDOUT param. https://docs.python.org/3/library/subprocess.html#subprocess.STDOUT

Ah, I see. It sounds like a good idea. Let me check how much changes it requires in the code.

[KarolGongola]

It is much better. Thanks @fjmacagno

[KarolGongola]

@tatiana Is this fine for you now? Or do you prefer concatenation without "stdout" and "stderr" keywords?

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 96.28%. Comparing base (0edb07d) to head (0aa0b53).
Report is 4 commits behind head on main.

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #1390   +/-   ##
=======================================
  Coverage   96.28%   96.28%           
=======================================
  Files          68       68           
  Lines        4150     4150           
=======================================
  Hits         3996     3996           
  Misses        154      154           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[tatiana]

Thanks for the contribution and addressing the feedback, @KarolGongola , we're releasing this as part of 1.8