search

dbt-labs / dbt-bigquery

dbt-bigquery contains all of the code required to make dbt operate on a BigQuery database.
https://github.com/dbt-labs/dbt-bigquery
Apache License 2.0
210 stars 148 forks source link

[ADAP-382] [Bug] TestAccessGrantSucceeds routinely fails during automated testing, but passes upon re-run #614

Closed mikealfare closed 10 months ago

mikealfare commented 1 year ago

Is this a new bug in dbt-bigquery?

Current Behavior

Automated testing fails for tests/functional/adapter/test_grant_access_to.py::TestAccessGrantSucceeds::test_grant_access_succeeds on at least one version of python on Ubuntu images. However it always succeeds on a re-run.

This causes regular manual intervention with little value gained and decreases perceived value of the product due to regular "failed" status badges. It also could be indicative of a niche edge case (perhaps due to parallel calls to the same database, which is not a problem by the time we get to re-run).

Expected Behavior

Automated testing produces the same results upon re-run. Ideally this means it's all passing, but if this is an edge case, we should catch it in automated testing (e.g. by adding a test for that edge case).

Steps To Reproduce

View scheduled integration test results on main.

Relevant log output

=================================== FAILURES ===================================
______________ TestAccessGrantSucceeds.test_grant_access_succeeds ______________
[gw1] linux -- Python 3.10.10 /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/bin/python

self = <test_grant_access_to.TestAccessGrantSucceeds object at 0x7f11a65e63b0>
project = <dbt.tests.fixtures.project.TestProjInfo object at 0x7f11860e3c10>

    def test_grant_access_succeeds(self, project):
        # Need to run twice to validate idempotency
>       results = run_dbt(["run"])

/home/runner/work/dbt-bigquery/dbt-bigquery/tests/functional/adapter/test_grant_access_to.py:46: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

args = ['run', '--project-dir', '/tmp/pytest-of-runner/pytest-0/popen-gw1/project13', '--profiles-dir', '/tmp/pytest-of-runner/pytest-0/popen-gw1/profile13']
expect_pass = True

    def run_dbt(args: List[str] = None, expect_pass=True):
        # Ignore logbook warnings
        warnings.filterwarnings("ignore", category=DeprecationWarning, module="logbook")

        # reset global vars
        reset_metadata_vars()

        # The logger will complain about already being initialized if
        # we don't do this.
        log_manager.reset_handlers()
        if args is None:
            args = ["run"]

        print("\n\nInvoking dbt with ***".format(args))
        from dbt.flags import get_flags

        flags = get_flags()
        project_dir = getattr(flags, "PROJECT_DIR", None)
        profiles_dir = getattr(flags, "PROFILES_DIR", None)
        if project_dir and "--project-dir" not in args:
            args.extend(["--project-dir", project_dir])
        if profiles_dir and "--profiles-dir" not in args:
            args.extend(["--profiles-dir", profiles_dir])
        dbt = dbtRunner()
        res, success = dbt.invoke(args)

        if expect_pass is not None:
>           assert success == expect_pass, "dbt exit state did not match expected"
E           AssertionError: dbt exit state did not match expected

/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/tests/util.py:98: AssertionError
---------------------------- Captured stdout setup -----------------------------

=== Test project_root: /tmp/pytest-of-runner/pytest-0/popen-gw1/project13
---------------------------- Captured logbook setup ----------------------------
[DEBUG] file_log: ***"data": ***"conn_name": "_test", "conn_type": "bigquery"***, "info": ***"category": "", "code": "E005", "extra": ***, "invocation_id": "92202926-02d6-44eb-963a-0992ed6db5b2", "level": "debug", "msg": "Acquiring new bigquery connection '_test'", "name": "NewConnection", "pid": 2007, "thread": "MainThread", "ts": "2023-03-17T15:27:54.935696Z"***
[DEBUG] file_log: ***"data": ***"relation": ***"database": "dbt-test-env", "identifier": null, "schema": "test16790668743279247394_test_grant_access_to"***, "info": ***"category": "", "code": "E020", "extra": ***, "invocation_id": "92202926-02d6-44eb-963a-0992ed6db5b2", "level": "debug", "msg": "Creating schema \"ReferenceKeyMsg(database='dbt-test-env', schema='test16790668743279247394_test_grant_access_to', identifier=None)\"", "name": "SchemaCreation", "pid": 2007, "thread": "MainThread", "ts": "2023-03-17T15:27:54.936541Z"***
[DEBUG] file_log: ***"data": ***"connection_state": "closed"***, "info": ***"category": "", "code": "E037", "extra": ***, "invocation_id": "92202926-02d6-44eb-963a-0992ed6db5b2", "level": "debug", "msg": "Opening a new connection, currently in state closed", "name": "NewConnectionOpening", "pid": 2007, "thread": "MainThread", "ts": "2023-03-17T15:27:54.939665Z"***
[DEBUG] file_log: ***"data": ***"conn_name": "_test", "sql": "create schema if not exists `dbt-test-env`.`test16790668743279247394_test_grant_access_to`\n  "***, "info": ***"category": "", "code": "E016", "extra": ***, "invocation_id": "92202926-02d6-44eb-963a-0992ed6db5b2", "level": "debug", "msg": "On _test: create schema if not exists `dbt-test-env`.`test16790668743279247394_test_grant_access_to`\n  ", "name": "SQLQuery", "pid": 2007, "thread": "MainThread", "ts": "2023-03-17T15:27:54.991765Z"***
[DEBUG] file_log: ***"data": ***"args": [], "base_msg": "https://console.cloud.google.com/bigquery?project=dbt-test-env&j=bq:US:9e721388-f0ea-4fa6-b44f-df675e48ff46&page=queryresults", "name": "BigQuery"***, "info": ***"category": "", "code": "E001", "extra": ***, "invocation_id": "92202926-02d6-44eb-963a-0992ed6db5b2", "level": "debug", "msg": "BigQuery adapter: https://console.cloud.google.com/bigquery?project=dbt-test-env&j=bq:US:9e721388-f0ea-4fa6-b44f-df675e48ff46&page=queryresults", "name": "AdapterEventDebug", "pid": 2007, "thread": "MainThread", "ts": "2023-03-17T15:27:56.047899Z"***
----------------------------- Captured stdout call -----------------------------

Invoking dbt with ['run']
15:27:56  Running with dbt=1.5.0-b4
15:27:56  Unable to do partial parsing because saved manifest not found. Starting full parse.
15:27:57  Found 2 models, 0 tests, 0 snapshots, 0 analyses, 352 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics, 0 groups
15:27:57  
15:27:57  Concurrency: 1 threads (target='default')
15:27:57  
15:27:57  1 of 2 START sql view model test16790668743279247394_test_grant_access_to.select_1  [RUN]
15:27:59  Unhandled error while executing target/run/test/models/select_1.sql
412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
15:27:59  1 of 2 ERROR creating sql view model test16790668743279247394_test_grant_access_to.select_1  [ERROR in 1.59s]
15:27:59  2 of 2 START sql table model test16790668743279247394_test_grant_access_to.select_1_table  [RUN]
15:28:02  2 of 2 OK created sql table model test16790668743279247394_test_grant_access_to.select_1_table  [CREATE TABLE (1.0 rows, 0 processed) in 2.47s]
15:28:02  
15:28:02  Finished running 1 view model, 1 table model in 0 hours 0 minutes and 4.91 seconds (4.91s).
15:28:02  
15:28:02  Completed with 1 error and 0 warnings:
15:28:02  
15:28:02  412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
15:28:02  
15:28:02  Done. PASS=1 WARN=0 ERROR=1 SKIP=0 TOTAL=2
---------------------------- Captured logbook call -----------------------------
[INFO] stdout_log: 15:27:56  Running with dbt=1.5.0-b4
[INFO] file_log: 

============================== 2023-03-17 15:27:56.056578 | 92202926-02d6-44eb-963a-0992ed6db5b2 ==============================
15:27:56.056578 [info ] [MainThread]: Running with dbt=1.5.0-b4
[DEBUG] file_log: 15:27:56.057298 [debug] [MainThread]: running dbt with arguments ***'use_colors': 'True', 'partial_parse': 'True', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'cache_selected_only': 'False', 'fail_fast': 'False', 'log_format': 'default', 'quiet': 'False', 'warn_error': 'None', 'static_parser': 'True', 'no_print': 'None', 'log_cache_events': 'False', 'write_json': 'True', 'debug': 'False', 'printer_width': '80', 'log_path': '/home/runner/work/dbt-bigquery/dbt-bigquery/logs/test16790668743279247394', 'send_anonymous_usage_stats': 'False', 'profiles_dir': '/tmp/pytest-of-runner/pytest-0/popen-gw1/profile13', 'indirect_selection': 'eager', 'target_path': 'None', 'introspect': 'True', 'use_experimental_parser': 'False', 'version_check': 'True'***
[DEBUG] file_log: 15:27:56.057627 [debug] [MainThread]: Connection '_test' was properly closed.
[DEBUG] file_log: 15:27:56.101652 [debug] [MainThread]: checksum: 95c342bce7afc496d53d52bda6b7c05f8d0378ea9d304e072441b25ae494a33e, vars: ***, profile: None, target: None, version: 1.5.0b4
[INFO] stdout_log: 15:27:56  Unable to do partial parsing because saved manifest not found. Starting full parse.
[INFO] file_log: 15:27:56.102346 [info ] [MainThread]: Unable to do partial parsing because saved manifest not found. Starting full parse.
[DEBUG] file_log: 15:27:57.073745 [debug] [MainThread]: 1699: static parser successfully parsed select_1_table.sql
[DEBUG] file_log: 15:27:57.078338 [debug] [MainThread]: 1699: static parser successfully parsed select_1.sql
[INFO] stdout_log: 15:27:57  Found 2 models, 0 tests, 0 snapshots, 0 analyses, 352 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics, 0 groups
[INFO] file_log: 15:27:57.143386 [info ] [MainThread]: Found 2 models, 0 tests, 0 snapshots, 0 analyses, 352 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics, 0 groups
[INFO] stdout_log: 15:27:57  
[INFO] file_log: 15:27:57.144684 [info ] [MainThread]: 
[DEBUG] file_log: 15:27:57.145703 [debug] [MainThread]: Acquiring new bigquery connection 'master'
[DEBUG] file_log: 15:27:57.146990 [debug] [ThreadPool]: Acquiring new bigquery connection 'list_dbt-test-env'
[DEBUG] file_log: 15:27:57.147471 [debug] [ThreadPool]: Opening a new connection, currently in state init
[DEBUG] file_log: 15:27:57.627064 [debug] [ThreadPool]: Re-using an available connection from the pool (formerly list_dbt-test-env, now list_dbt-test-env_test16790668743279247394_test_grant_access_to)
[DEBUG] file_log: 15:27:57.627992 [debug] [ThreadPool]: Opening a new connection, currently in state closed
[INFO] stdout_log: 15:27:57  Concurrency: 1 threads (target='default')
[INFO] file_log: 15:27:57.983503 [info ] [MainThread]: Concurrency: 1 threads (target='default')
[INFO] stdout_log: 15:27:57  
[INFO] file_log: 15:27:57.984236 [info ] [MainThread]: 
[DEBUG] file_log: 15:27:57.985881 [debug] [Thread-237]: Began running node model.test.select_1
[INFO] stdout_log: 15:27:57  1 of 2 START sql view model test16790668743279247394_test_grant_access_to.select_1  [RUN]
[INFO] file_log: 15:27:57.986478 [info ] [Thread-237]: 1 of 2 START sql view model test16790668743279247394_test_grant_access_to.select_1  [RUN]
[DEBUG] file_log: 15:27:57.987660 [debug] [Thread-237]: Re-using an available connection from the pool (formerly list_dbt-test-env_test16790668743279247394_test_grant_access_to, now model.test.select_1)
[DEBUG] file_log: 15:27:57.988011 [debug] [Thread-237]: Began compiling node model.test.select_1
[DEBUG] file_log: 15:27:57.992590 [debug] [Thread-237]: Writing injected SQL for node "model.test.select_1"
[DEBUG] file_log: 15:27:57.993345 [debug] [Thread-237]: Timing info for model.test.select_1 (compile): 2023-03-17 15:27:57.988229 => 2023-03-17 15:27:57.993254
[DEBUG] file_log: 15:27:57.993716 [debug] [Thread-237]: Began executing node model.test.select_1
[DEBUG] file_log: 15:27:57.997774 [debug] [Thread-237]: Writing runtime sql for node "model.test.select_1"
[DEBUG] file_log: 15:27:57.998356 [debug] [Thread-237]: Opening a new connection, currently in state closed
[DEBUG] file_log: 15:27:58.051257 [debug] [Thread-237]: On model.test.select_1: /* ***"app": "dbt", "dbt_version": "1.5.0b4", "profile_name": "test", "target_name": "default", "node_id": "model.test.select_1"*** */

  create or replace view `dbt-test-env`.`test16790668743279247394_test_grant_access_to`.`select_1`
  OPTIONS()

  as 
SELECT 1 as one;

[DEBUG] file_log: 15:27:59.086174 [debug] [Thread-237]: BigQuery adapter: https://console.cloud.google.com/bigquery?project=dbt-test-env&j=bq:US:41058d16-4bcb-4fdc-a161-aadebd982651&page=queryresults
[DEBUG] file_log: 15:27:59.574784 [debug] [Thread-237]: Timing info for model.test.select_1 (execute): 2023-03-17 15:27:57.993951 => 2023-03-17 15:27:59.574648
Error:  stdout_log: 15:27:59  Unhandled error while executing target/run/test/models/select_1.sql
412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
Error: og: 15:27:59.575811 [error] [Thread-237]: Unhandled error while executing target/run/test/models/select_1.sql
412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
[DEBUG] file_log: 15:27:59.577442 [debug] [Thread-237]: Traceback (most recent call last):
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/task/base.py", line 387, in safe_run
    result = self.compile_and_execute(manifest, ctx)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/task/base.py", line 336, in compile_and_execute
    result = self.run(ctx.node, manifest)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/task/base.py", line 435, in run
    return self.execute(compiled_node, manifest)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/task/run.py", line 277, in execute
    result = MacroGenerator(
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/clients/jinja.py", line 330, in __call__
    return self.call_macro(*args, **kwargs)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/dbt/clients/jinja.py", line 257, in call_macro
    return macro(*args, **kwargs)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/jinja2/runtime.py", line 763, in __call__
    return self._invoke(arguments, autoescape)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/jinja2/runtime.py", line 777, in _invoke
    rv = self._func(*arguments)
  File "<template>", line 55, in macro
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/jinja2/sandbox.py", line 393, in call
    return __context.call(__obj, *args, **kwargs)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/jinja2/runtime.py", line 298, in call
    return __obj(*args, **kwargs)
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/dbt/adapters/bigquery/impl.py", line 840, in grant_access_to
    client.update_dataset(dataset, ["access_entries"])
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/cloud/bigquery/client.py", line 1117, in update_dataset
    api_response = self._call_api(
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/cloud/bigquery/client.py", line 797, in _call_api
    return call()
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/api_core/retry.py", line 349, in retry_wrapped_func
    return retry_target(
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/api_core/retry.py", line 191, in retry_target
    return target()
  File "/home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/cloud/_http/__init__.py", line 494, in api_request
    raise exceptions.from_http_response(response)
google.api_core.exceptions.PreconditionFailed: 412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH

Error:  stdout_log: 15:27:59  1 of 2 ERROR creating sql view model test16790668743279247394_test_grant_access_to.select_1  [ERROR in 1.59s]
Error: og: 15:27:59.578135 [error] [Thread-237]: 1 of 2 ERROR creating sql view model test16790668743279247394_test_grant_access_to.select_1  [ERROR in 1.59s]
[DEBUG] file_log: 15:27:59.578683 [debug] [Thread-237]: Finished running node model.test.select_1
[DEBUG] file_log: 15:27:59.579134 [debug] [Thread-237]: Began running node model.test.select_1_table
[INFO] stdout_log: 15:27:59  2 of 2 START sql table model test16790668743279247394_test_grant_access_to.select_1_table  [RUN]
[INFO] file_log: 15:27:59.579826 [info ] [Thread-237]: 2 of 2 START sql table model test16790668743279247394_test_grant_access_to.select_1_table  [RUN]
[DEBUG] file_log: 15:27:59.580763 [debug] [Thread-237]: Re-using an available connection from the pool (formerly model.test.select_1, now model.test.select_1_table)
[DEBUG] file_log: 15:27:59.581133 [debug] [Thread-237]: Began compiling node model.test.select_1_table
[DEBUG] file_log: 15:27:59.585562 [debug] [Thread-237]: Writing injected SQL for node "model.test.select_1_table"
[DEBUG] file_log: 15:27:59.586063 [debug] [Thread-237]: Timing info for model.test.select_1_table (compile): 2023-03-17 15:27:59.581366 => 2023-03-17 15:27:59.585988
[DEBUG] file_log: 15:27:59.586416 [debug] [Thread-237]: Began executing node model.test.select_1_table
[DEBUG] file_log: 15:27:59.590307 [debug] [Thread-237]: Writing runtime sql for node "model.test.select_1_table"
[DEBUG] file_log: 15:27:59.590806 [debug] [Thread-237]: Opening a new connection, currently in state closed
[DEBUG] file_log: 15:27:59.642991 [debug] [Thread-237]: On model.test.select_1_table: /* ***"app": "dbt", "dbt_version": "1.5.0b4", "profile_name": "test", "target_name": "default", "node_id": "model.test.select_1_table"*** */

    create or replace table `dbt-test-env`.`test16790668743279247394_test_grant_access_to`.`select_1_table`

    OPTIONS()
    as (

SELECT 1 as one
    );

[DEBUG] file_log: 15:28:02.047723 [debug] [Thread-237]: BigQuery adapter: https://console.cloud.google.com/bigquery?project=dbt-test-env&j=bq:US:092ad622-46f5-4803-b19a-79948971a70c&page=queryresults
[DEBUG] file_log: 15:28:02.050047 [debug] [Thread-237]: Timing info for model.test.select_1_table (execute): 2023-03-17 15:27:59.586649 => 2023-03-17 15:28:02.049965
[INFO] stdout_log: 15:28:02  2 of 2 OK created sql table model test16790668743279247394_test_grant_access_to.select_1_table  [CREATE TABLE (1.0 rows, 0 processed) in 2.47s]
[INFO] file_log: 15:28:02.051231 [info ] [Thread-237]: 2 of 2 OK created sql table model test16790668743279247394_test_grant_access_to.select_1_table  [CREATE TABLE (1.0 rows, 0 processed) in 2.47s]
[DEBUG] file_log: 15:28:02.051842 [debug] [Thread-237]: Finished running node model.test.select_1_table
[DEBUG] file_log: 15:28:02.054085 [debug] [MainThread]: Connection 'master' was properly closed.
[DEBUG] file_log: 15:28:02.054408 [debug] [MainThread]: Connection 'model.test.select_1_table' was properly closed.
[INFO] stdout_log: 15:28:02  
[INFO] file_log: 15:28:02.054712 [info ] [MainThread]: 
[INFO] stdout_log: 15:28:02  Finished running 1 view model, 1 table model in 0 hours 0 minutes and 4.91 seconds (4.91s).
[INFO] file_log: 15:28:02.055122 [info ] [MainThread]: Finished running 1 view model, 1 table model in 0 hours 0 minutes and 4.91 seconds (4.91s).
[DEBUG] file_log: 15:28:02.055813 [debug] [MainThread]: Command end result
[INFO] stdout_log: 15:28:02  
[INFO] file_log: 15:28:02.074446 [info ] [MainThread]: 
[INFO] stdout_log: 15:28:02  Completed with 1 error and 0 warnings:
[INFO] file_log: 15:28:02.075143 [info ] [MainThread]: Completed with 1 error and 0 warnings:
[INFO] stdout_log: 15:28:02  
[INFO] file_log: 15:28:02.075552 [info ] [MainThread]: 
Error:  stdout_log: 15:28:02  412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
Error: og: 15:28:02.075955 [error] [MainThread]: 412 PATCH https://bigquery.googleapis.com/bigquery/v2/projects/***/datasets/GrantAccessTest?prettyPrint=false: Resource ***:GrantAccessTest did not meet condition IF_MATCH
[INFO] stdout_log: 15:28:02  
[INFO] file_log: 15:28:02.076346 [info ] [MainThread]: 
[INFO] stdout_log: 15:28:02  Done. PASS=1 WARN=0 ERROR=1 SKIP=0 TOTAL=2
[INFO] file_log: 15:28:02.076743 [info ] [MainThread]: Done. PASS=1 WARN=0 ERROR=1 SKIP=0 TOTAL=2
[DEBUG] file_log: 15:28:02.077259 [debug] [MainThread]: Flushing usage events
-------------------------- Captured logbook teardown ---------------------------
[DEBUG] file_log: 15:28:02.352794 [debug] [MainThread]: Acquiring new bigquery connection '_test'
[DEBUG] file_log: 15:28:02.353369 [debug] [MainThread]: BigQuery adapter: Dropping schema "dbt-test-env.test16790668743279247394_test_grant_access_to".
[DEBUG] file_log: 15:28:02.353672 [debug] [MainThread]: Dropping schema "ReferenceKeyMsg(database='dbt-test-env', schema='test16790668743279247394_test_grant_access_to', identifier=None)".
[DEBUG] file_log: 15:28:02.353978 [debug] [MainThread]: Opening a new connection, currently in state init
=============================== warnings summary ===============================
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: 36 warnings
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: 16 warnings
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google.cloud')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2309: 16 warnings
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2309: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google.logging')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google.iam')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/pkg_resources/__init__.py:2804: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('ruamel')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

.tox/integration-bigquery/lib/python3.10/site-packages/google/rpc/__init__.py:20
.tox/integration-bigquery/lib/python3.10/site-packages/google/rpc/__init__.py:20
.tox/integration-bigquery/lib/python3.10/site-packages/google/rpc/__init__.py:20
.tox/integration-bigquery/lib/python3.10/site-packages/google/rpc/__init__.py:20
  /home/runner/work/dbt-bigquery/dbt-bigquery/.tox/integration-bigquery/lib/python3.10/site-packages/google/rpc/__init__.py:20: DeprecationWarning: Deprecated call to `pkg_resources.declare_namespace('google.rpc')`.
  Implementing implicit namespace packages (as specified in PEP 420) is preferred to `pkg_resources.declare_namespace`. See https://setuptools.pypa.io/en/latest/references/keywords.html#keyword-namespace-packages

tests/functional/test_changing_partitions.py: 15 warnings
tests/functional/adapter/simple_bigquery_view/test_simple_bigquery_view.py: 3 warnings
  /home/runner/work/dbt-bigquery/dbt-bigquery/dbt/adapters/bigquery/impl.py:556: PendingDeprecationWarning: This method will be deprecated in future versions. Please use Table.time_partitioning.type_ instead.

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
--------------------- CSV report: integration_results.csv ----------------------
=========================== short test summary info ============================
FAILED tests/functional/adapter/test_grant_access_to.py::TestAccessGrantSucceeds::test_grant_access_succeeds - AssertionError: dbt exit state did not match expected
====== 1 failed, 140 passed, 3 skipped, 106 warnings in 760.23s (0:12:40) ======
integration-bigquery: exit 1 (763.64 seconds) /home/runner/work/dbt-bigquery/dbt-bigquery> .tox/integration-bigquery/bin/python -m pytest -vv tests/functional --profile service_account pid=1999
  integration-bigquery: FAIL code 1 (805.99=setup[42.35]+cmd[763.64] seconds)
  evaluation failed :( (806.25 seconds)
Error: Process completed with exit code 1.

Environment

- OS: ubuntu:latest
- Python: various, it's not always the same version
- dbt-core: 1.5.latest
- dbt-bigquery: 1.5.latest

Additional Context

No response

mikealfare commented 1 year ago

This appears to be related to this issue: https://github.com/dbt-labs/dbt-bigquery/issues/126. The cause and presentation appear to be identical.

github-actions[bot] commented 10 months ago

This issue has been marked as Stale because it has been open for 180 days with no activity. If you would like the issue to remain open, please comment on the issue or else it will be closed in 7 days.

github-actions[bot] commented 10 months ago

Although we are closing this issue as stale, it's not gone forever. Issues can be reopened if there is renewed community interest. Just add a comment to notify the maintainers.