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.

Sign up for GitHub

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

Jump to bottom

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

Closed
2 tasks done
mikealfare opened this issue Mar 17, 2023 · 3 comments · Fixed by #674
Closed
2 tasks done

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

mikealfare opened this issue Mar 17, 2023 · 3 comments · Fixed by #674
Assignees
@mikealfare
Labels
Stale type:bug Something isn't working

Comments

@mikealfare
Copy link
Contributor

Is this a new bug in dbt-bigquery?

  • I believe this is a new bug in dbt-bigquery
  • I have searched the existing issues, and I could not find an existing issue for this bug

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 mikealfare added type:bug Something isn't working triage:product labels Mar 17, 2023
@github-actions github-actions bot changed the title [Bug] TestAccessGrantSucceeds routinely fails during automated testing, but passes upon re-run [ADAP-382] [Bug] TestAccessGrantSucceeds routinely fails during automated testing, but passes upon re-run Mar 17, 2023
@mikealfare mikealfare self-assigned this Apr 21, 2023
@mikealfare
Copy link
Contributor Author

This appears to be related to this issue: #126. The cause and presentation appear to be identical.

@mikealfare mikealfare mentioned this issue Apr 23, 2023
Merged
6 tasks
This was referenced Apr 24, 2023
Merged
Merged
@mikealfare mikealfare reopened this Apr 26, 2023
@github-actions
Copy link
Contributor

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 github-actions bot added the Stale label Oct 24, 2023
@github-actions
Copy link
Contributor

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.

@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Oct 31, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@mikealfare mikealfare

Labels
Stale type:bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

ADAP-382: Address TestAccessGrantSucceeds sporadic failure dbt-labs/dbt-bigquery
2 participants
@mikealfare @dbeatty10