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

Log, but allow, failures during cleanup rollbacks. #1647

Conversation

levimalott
Copy link
Contributor

In Postgres, rollbacks can fail if the transaction was killed
by the database. One common scenario is that the
idle_in_transaction_session_timeout is enabled.

If the
transaction was cancelled, the connection is left open
in dbt. dbt attempts to close that connection after issuing
a ROLLBACK. But it fails since the transaction was severed.
Since the cleanup is carried out in a finally statement, the
psycopg2.InternalDatabaseError is thrown and prevents the
test case results from ever being shown.

Changes here wrap the ROLLBACK in a try-catch such that
if there is an exception thrown, it is logged appropriately,
but ultimately proceeds.

Before

Prior to this change, a failed rollback during cleanup would prevent the test results from every being shown as the exception is thrown during the finally clause.

Screen Shot 2019-07-31 at 10 32 04 AM

After

Here the exception is logged, but caught. Test case results are shown afterwards rather than dbt crashing.

Screen Shot 2019-07-31 at 10 32 27 AM

In Postgres, rollbacks can fail if the transaction was killed
by the database. One common scenario is that the
`idle_in_transaction_session_timeout` is enabled.

If the
transaction was cancelled, the connection is left open
in `dbt`. `dbt` attempts to close that connection after issuing
a `ROLLBACK`. But it fails since the transaction was severed.
Since the cleanup is carried out in a `finally` statement, the
`psycopg2.InternalDatabaseError` is thrown and prevents the
test case results from ever being shown.

Changes here wrap the `ROLLBACK` in a try-catch such that
if there is an exception thrown, it is logged appropriately,
but ultimately proceeds.
@drewbanin drewbanin self-requested a review July 31, 2019 19:23
Copy link
Contributor

@drewbanin drewbanin left a comment

Choose a reason for hiding this comment

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

Thanks for the PR @levimalott! This looks great!

One comment about the log output, let me know if you'd like to discuss! I think we should be able to get this merged for the 0.14.1 release. Thanks again!

try:
connection.handle.rollback()
except Exception:
logger.exception('Failed to rollback {}'.format(connection.name))
Copy link
Contributor

Choose a reason for hiding this comment

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

Can we use logger.error instead of logger.exception here? We try not to log stack traces to stdout. In this case, it might be appropriate to log the exception to the debug logs, eg. with logger.debug('', exc_info=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.

Can we use logger.error instead of logger.exception here? We try not to log stack traces to stdout. In this case, it might be appropriate to log the exception to the debug logs, eg. with logger.debug('', exc_info=True).

Makes sense! I'll have an update shortly.

@drewbanin
Copy link
Contributor

Thanks! Just kicked off the CI tests :)

@drewbanin
Copy link
Contributor

Ah! Looks like there's just a pep8 (formatting) issue:

core/dbt/adapters/base/connections.py:254:80: E501 line too long (88 > 79 characters)

@levimalott
Copy link
Contributor Author

Ah! Looks like there's just a pep8 (formatting) issue:

core/dbt/adapters/base/connections.py:254:80: E501 line too long (88 > 79 characters)

Should be good now 😎
Screen Shot 2019-07-31 at 4 22 04 PM

@drewbanin
Copy link
Contributor

Thanks @levimalott! kicking off the tests now :)

@drewbanin
Copy link
Contributor

Merging this! Thanks @levimalott - this is going out in dbt v0.14.1

@drewbanin drewbanin merged commit 4478a89 into dbt-labs:dev/0.14.1 Aug 2, 2019
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.

2 participants