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

Ct 866/migrate hook tests fixed #5760

Merged
merged 11 commits into from
Sep 6, 2022
Merged

Conversation

VersusFacit
Copy link
Contributor

@VersusFacit VersusFacit commented Sep 5, 2022

Description

This was supposed to a simple, humble test conversion. Instead, I fixed a weird timezone error that intermittently arises on snapshots tests. And I finally found the original root of the weird structured logging problem.

So what the heck happened in this PR

There was...a lot behind these code changes.

Without the presence of certain integration tests (but not others -- this I was never able to solve), DBT_LOG_FORMAT doesn't get set to json for pre-integration-test class instantiations. It shouldn't be NULL, but flags.py doesn't get invoked for certain integration test events....unless you do a secondary check.

You can see this happen when removing 014 or 015 and I presume many many others. When I removed test014, the structured log test broke because the internal FLAG was not being set that suppresses a handful of debug connection messages on each thread.

With this PR's ancillary check in place, the test (thank goodness) passes the structured logging check--that garbage data is no longer coughed up.

PRs #5705 #5654 were the poor PRs that I subjected extensive CI testing to when coaxing out exactly what was going on and how our CI differs from our local testing environments.

Checklist

@cla-bot cla-bot bot added the cla:yes label Sep 5, 2022
@github-actions
Copy link
Contributor

github-actions bot commented Sep 5, 2022

Thank you for your pull request! We could not find a changelog entry for this change. For details on how to document a change, see the contributing guide.

@@ -24,6 +36,12 @@ def datetime_snapshot():
return begin_snapshot_datetime


@pytest.fixture(scope="class", autouse=True)
def setUp(project):
Copy link
Contributor Author

Choose a reason for hiding this comment

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

was messing around in here and left this change as it better reflects our current best practices

@@ -79,7 +94,7 @@ def test_snapshot_hard_delete(project):
for result in snapshotted[10:]:
# result is a tuple, the dbt_valid_to column is the latest
assert isinstance(result[-1], datetime)
assert result[-1].replace(tzinfo=pytz.UTC) >= invalidated_snapshot_datetime
assert result[-1].replace(tzinfo=currenttz()) >= invalidated_snapshot_datetime
Copy link
Contributor Author

@VersusFacit VersusFacit Sep 5, 2022

Choose a reason for hiding this comment

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

this fixes an intermittent error that will show up in my (and others', judging from slack threads) local test invocations. I ran into, and fixed, this as part of getting my local CI to precisely match our remote CI

@VersusFacit VersusFacit marked this pull request as ready for review September 5, 2022 07:49
@VersusFacit VersusFacit requested review from a team as code owners September 5, 2022 07:49
@VersusFacit VersusFacit self-assigned this Sep 5, 2022
Copy link
Contributor

@nathaniel-may nathaniel-may left a comment

Choose a reason for hiding this comment

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

Great job finding these two VERY sneaky issues. I'm so happy we can finally put this to rest.

.changes/unreleased/Under the Hood-20220905-001749.yaml Outdated Show resolved Hide resolved
core/dbt/events/functions.py Outdated Show resolved Hide resolved
tests/functional/hooks/fixtures.py Show resolved Hide resolved
Comment on lines +23 to +27
def currenttz():
if time.daylight:
return timezone(timedelta(seconds=-time.altzone), time.tzname[1])
else:
return timezone(timedelta(seconds=-time.timezone), time.tzname[0])
Copy link
Contributor

Choose a reason for hiding this comment

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

I suspect there might be a better way to do this, but I'm find merging this if it's not obvious.

Copy link
Contributor Author

@VersusFacit VersusFacit Sep 6, 2022

Choose a reason for hiding this comment

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

Honestly, it's hard to find an answer in the std lib. I went with this to avoid adding a third party library. Not tied to any which way though.

Copy link
Contributor

@gshank gshank 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 glad you got this working, but I don't think the solution is right yet. I think we need to be calling flags.set_from_args someplace.

# Flags is not set in the integration test suite but is by the environment.
# DBT_LOG_FORMAT is used in our test suite so checking for it's presence is key.
this.format_json = (
flags.LOG_FORMAT == "json" or os.environ.get("DBT_LOG_FORMAT", "json") == "json"
Copy link
Contributor

Choose a reason for hiding this comment

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

I don't think that this is correct. If the log_format isn't set by env_var, user_config or cli option, the default is None. This is basically changing the default to be 'json'. If the log_format isn't set and it IS set in an env_var, it means that flags.set_from_args has not been called someplace where it ought to be.

Copy link
Contributor Author

@VersusFacit VersusFacit Sep 6, 2022

Choose a reason for hiding this comment

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

This is basically changing the default to be 'json'.

Yep, that was to get this working, and I think I mentioned (or at least intended to) this was just my naive solution after identifying the problem.

If the log_format isn't set and it IS set in an env_var, it means that flags.set_from_args has not been called someplace where it ought to be.

See, this is exactly where I was hoping someone more familiar would know the answer. Let me see about getting that routine called and reverting this line.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Think I've got something better now. Best part is once the base.py is removed, this patch will go with it, i.e. the fix is scoped to integration tests

@VersusFacit VersusFacit requested a review from gshank September 6, 2022 18:56
Copy link
Contributor

@gshank gshank left a comment

Choose a reason for hiding this comment

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

In theory, there might be a better place to put the flags.set_from_args call (including the user_config and args params), but integration/base.py is pretty convoluted and as you say is going to go away. So I'm fine with this as a way to move forward :)

@VersusFacit VersusFacit merged commit 0f6e4f0 into main Sep 6, 2022
@VersusFacit VersusFacit deleted the CT-866/migrate_hook_tests_fixed branch September 6, 2022 19:22
agoblet pushed a commit to BigDataRepublic/dbt-core that referenced this pull request Sep 16, 2022
* Finish converting first test file.
* Finish test conversion.
* Remove old integration hook tests.
* Move location of schema.yml to models directory.
* fix snapshot delete test that was failing
* Add the extra env var check for our CI.
* Add changelog
* Remove naive json flag check and instead force all integration tests to check for environment variables using flag routine.
* Revise the changelog to be more of an explanation.

Co-authored-by: Mila Page <versusfacit@users.noreply.github.com>
josephberni pushed a commit to Gousto/dbt-core that referenced this pull request Sep 16, 2022
* Finish converting first test file.
* Finish test conversion.
* Remove old integration hook tests.
* Move location of schema.yml to models directory.
* fix snapshot delete test that was failing
* Add the extra env var check for our CI.
* Add changelog
* Remove naive json flag check and instead force all integration tests to check for environment variables using flag routine.
* Revise the changelog to be more of an explanation.

Co-authored-by: Mila Page <versusfacit@users.noreply.github.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants