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

dbt should not crash when it sees Materialized Views #1698

Closed
tomtl opened this issue Aug 26, 2019 · 5 comments · Fixed by #1833
Closed

dbt should not crash when it sees Materialized Views #1698

tomtl opened this issue Aug 26, 2019 · 5 comments · Fixed by #1833
Labels
bug Something isn't working redshift
Milestone
Louisa May Alcott

Comments

@tomtl
Copy link

tomtl commented Aug 26, 2019 •
edited
Loading

Describe the bug

When I run dbt run I get an error of "Cache inconsistency detected" referring to a materialized view in the same schema, not referenced in this DBT project, but part of a previous DBT project. Manually dropping the materialized view fixes the problem.

Steps To Reproduce

Created a new DBT project that does not include mention of "cpp009_business_spend". Run dbt run. Get an error "dbt.exceptions.InternalException: Cache inconsistency detected: in add_link, referenced link key _ReferenceKey(database='reference', schema='tlee', identifier='cpp009_business_spend') not in cache!" (see below for full error). This was using DBT 0.13.1 installed with brew. I also updated to version 0.14.0 and got the same error.

Using SQL to run DROP MATERIALIZED VIEW tlee.cpp009_business_spend CASCADE; fixes the problem and afterward DBT can run without any problems.

Expected behavior

DBT should run without querying the "cpp009_business_spend" materialized view as it is not part of the DBT project.

Screenshots and log output

If applicable, add screenshots or log output to help explain your problem.

System information

DBT version 0.13.1 and 0.14.0 installed with Brew
Postgres 9.4
Mac OS current

The output of dbt --version:

dbt --version
installed version: 0.14.0
   latest version: 0.14.0

Up to date!

The output of python --version: Python 2.7.15

Additional context

STACK TRACE

dbt --debug run
​
Running with dbt=0.14.0
2019-08-26 10:41:40,953 (MainThread): Tracking: tracking
2019-08-26 10:41:40,959 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10eda3bd0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10edae510>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10eda3b90>]}
2019-08-26 10:41:41,213 (MainThread): Parsing macros/core.sql
2019-08-26 10:41:41,219 (MainThread): Parsing macros/materializations/helpers.sql
2019-08-26 10:41:41,227 (MainThread): Parsing macros/materializations/snapshot/snapshot_merge.sql
2019-08-26 10:41:41,229 (MainThread): Parsing macros/materializations/snapshot/strategies.sql
2019-08-26 10:41:41,242 (MainThread): Parsing macros/materializations/snapshot/snapshot.sql
2019-08-26 10:41:41,261 (MainThread): Parsing macros/materializations/seed/seed.sql
2019-08-26 10:41:41,275 (MainThread): Parsing macros/materializations/incremental/incremental.sql
2019-08-26 10:41:41,282 (MainThread): Parsing macros/materializations/common/merge.sql
2019-08-26 10:41:41,288 (MainThread): Parsing macros/materializations/table/table.sql
2019-08-26 10:41:41,293 (MainThread): Parsing macros/materializations/view/view.sql
2019-08-26 10:41:41,298 (MainThread): Parsing macros/materializations/view/create_or_replace_view.sql
2019-08-26 10:41:41,303 (MainThread): Parsing macros/etc/get_custom_alias.sql
2019-08-26 10:41:41,304 (MainThread): Parsing macros/etc/query.sql
2019-08-26 10:41:41,305 (MainThread): Parsing macros/etc/is_incremental.sql
2019-08-26 10:41:41,307 (MainThread): Parsing macros/etc/get_relation_comment.sql
2019-08-26 10:41:41,309 (MainThread): Parsing macros/etc/datetime.sql
2019-08-26 10:41:41,317 (MainThread): Parsing macros/etc/get_custom_schema.sql
2019-08-26 10:41:41,319 (MainThread): Parsing macros/adapters/common.sql
2019-08-26 10:41:41,348 (MainThread): Parsing macros/schema_tests/relationships.sql
2019-08-26 10:41:41,350 (MainThread): Parsing macros/schema_tests/not_null.sql
2019-08-26 10:41:41,351 (MainThread): Parsing macros/schema_tests/unique.sql
2019-08-26 10:41:41,352 (MainThread): Parsing macros/schema_tests/accepted_values.sql
2019-08-26 10:41:41,354 (MainThread): Parsing macros/catalog.sql
2019-08-26 10:41:41,356 (MainThread): Parsing macros/relations.sql
2019-08-26 10:41:41,357 (MainThread): Parsing macros/adapters.sql
2019-08-26 10:41:41,367 (MainThread): Parsing macros/materializations/snapshot_merge.sql
2019-08-26 10:41:41,380 (MainThread): Parsing model.towers.distance_sita2019_spgmi2018
2019-08-26 10:41:41,381 (MainThread): Acquiring new postgres connection "distance_sita2019_spgmi2018".
2019-08-26 10:41:41,381 (MainThread): Opening a new connection, currently in state init
2019-08-26 10:41:41,698 (MainThread): Parsing model.towers.distance_spgmi2018_sita2019
2019-08-26 10:41:41,699 (MainThread): Acquiring new postgres connection "distance_spgmi2018_sita2019".
2019-08-26 10:41:41,699 (MainThread): Re-using an available connection from the pool (formerly distance_sita2019_spgmi2018).
2019-08-26 10:41:41,705 (MainThread): Parsing model.towers.towers_spgmisita100m_20180701
2019-08-26 10:41:41,706 (MainThread): Acquiring new postgres connection "towers_spgmisita100m_20180701".
2019-08-26 10:41:41,706 (MainThread): Re-using an available connection from the pool (formerly distance_spgmi2018_sita2019).
2019-08-26 10:41:41,710 (MainThread): Parsing model.towers.towers_transform_sita2009_nearspgmi
2019-08-26 10:41:41,711 (MainThread): Acquiring new postgres connection "towers_transform_sita2009_nearspgmi".
2019-08-26 10:41:41,711 (MainThread): Re-using an available connection from the pool (formerly towers_spgmisita100m_20180701).
2019-08-26 10:41:41,716 (MainThread): Parsing model.towers.towers_transform_spgmi2018_buffers
2019-08-26 10:41:41,717 (MainThread): Acquiring new postgres connection "towers_transform_spgmi2018_buffers".
2019-08-26 10:41:41,717 (MainThread): Re-using an available connection from the pool (formerly towers_transform_sita2009_nearspgmi).
2019-08-26 10:41:41,723 (MainThread): Parsing model.towers.towers_transform_sita2019_buffers
2019-08-26 10:41:41,723 (MainThread): Acquiring new postgres connection "towers_transform_sita2019_buffers".
2019-08-26 10:41:41,724 (MainThread): Re-using an available connection from the pool (formerly towers_transform_spgmi2018_buffers).
2019-08-26 10:41:41,729 (MainThread): Parsing model.towers.towers_transform_sita2009_buffers
2019-08-26 10:41:41,729 (MainThread): Acquiring new postgres connection "towers_transform_sita2009_buffers".
2019-08-26 10:41:41,729 (MainThread): Re-using an available connection from the pool (formerly towers_transform_sita2019_buffers).
2019-08-26 10:41:41,734 (MainThread): Parsing model.towers.base_towers_sita_2019
2019-08-26 10:41:41,735 (MainThread): Acquiring new postgres connection "base_towers_sita_2019".
2019-08-26 10:41:41,735 (MainThread): Re-using an available connection from the pool (formerly towers_transform_sita2009_buffers).
2019-08-26 10:41:41,738 (MainThread): Parsing model.towers.base_towers_spgmi_2018
2019-08-26 10:41:41,739 (MainThread): Acquiring new postgres connection "base_towers_spgmi_2018".
2019-08-26 10:41:41,739 (MainThread): Re-using an available connection from the pool (formerly base_towers_sita_2019).
2019-08-26 10:41:41,742 (MainThread): Parsing model.towers.base_towers_sita_2009
2019-08-26 10:41:41,743 (MainThread): Acquiring new postgres connection "base_towers_sita_2009".
2019-08-26 10:41:41,743 (MainThread): Re-using an available connection from the pool (formerly base_towers_spgmi_2018).
2019-08-26 10:41:41,747 (MainThread): Parsing analysis.towers.morphology_spgmi_2018
2019-08-26 10:41:41,748 (MainThread): Acquiring new postgres connection "morphology_spgmi_2018".
2019-08-26 10:41:41,748 (MainThread): Re-using an available connection from the pool (formerly base_towers_sita_2009).
2019-08-26 10:41:41,780 (MainThread): Found 10 models, 0 tests, 0 snapshots, 1 analyses, 116 macros, 0 operations, 0 seed files, 0 sources
2019-08-26 10:41:41,781 (MainThread):
2019-08-26 10:41:41,781 (MainThread): Acquiring new postgres connection "master".
2019-08-26 10:41:41,781 (MainThread): Re-using an available connection from the pool (formerly morphology_spgmi_2018).
2019-08-26 10:41:41,792 (MainThread): Parsing macros/core.sql
2019-08-26 10:41:41,796 (MainThread): Parsing macros/materializations/helpers.sql
2019-08-26 10:41:41,802 (MainThread): Parsing macros/materializations/snapshot/snapshot_merge.sql
2019-08-26 10:41:41,804 (MainThread): Parsing macros/materializations/snapshot/strategies.sql
2019-08-26 10:41:41,815 (MainThread): Parsing macros/materializations/snapshot/snapshot.sql
2019-08-26 10:41:41,833 (MainThread): Parsing macros/materializations/seed/seed.sql
2019-08-26 10:41:41,846 (MainThread): Parsing macros/materializations/incremental/incremental.sql
2019-08-26 10:41:41,853 (MainThread): Parsing macros/materializations/common/merge.sql
2019-08-26 10:41:41,860 (MainThread): Parsing macros/materializations/table/table.sql
2019-08-26 10:41:41,865 (MainThread): Parsing macros/materializations/view/view.sql
2019-08-26 10:41:41,869 (MainThread): Parsing macros/materializations/view/create_or_replace_view.sql
2019-08-26 10:41:41,874 (MainThread): Parsing macros/etc/get_custom_alias.sql
2019-08-26 10:41:41,875 (MainThread): Parsing macros/etc/query.sql
2019-08-26 10:41:41,876 (MainThread): Parsing macros/etc/is_incremental.sql
2019-08-26 10:41:41,877 (MainThread): Parsing macros/etc/get_relation_comment.sql
2019-08-26 10:41:41,880 (MainThread): Parsing macros/etc/datetime.sql
2019-08-26 10:41:41,887 (MainThread): Parsing macros/etc/get_custom_schema.sql
2019-08-26 10:41:41,889 (MainThread): Parsing macros/adapters/common.sql
2019-08-26 10:41:41,918 (MainThread): Parsing macros/schema_tests/relationships.sql
2019-08-26 10:41:41,919 (MainThread): Parsing macros/schema_tests/not_null.sql
2019-08-26 10:41:41,920 (MainThread): Parsing macros/schema_tests/unique.sql
2019-08-26 10:41:41,921 (MainThread): Parsing macros/schema_tests/accepted_values.sql
2019-08-26 10:41:41,923 (MainThread): Parsing macros/catalog.sql
2019-08-26 10:41:41,926 (MainThread): Parsing macros/relations.sql
2019-08-26 10:41:41,927 (MainThread): Parsing macros/adapters.sql
2019-08-26 10:41:41,936 (MainThread): Parsing macros/materializations/snapshot_merge.sql
2019-08-26 10:41:42,036 (MainThread): Using postgres connection "master".
2019-08-26 10:41:42,036 (MainThread): On master:
    select distinct nspname from pg_namespace
​
2019-08-26 10:41:42,119 (MainThread): SQL status: SELECT 370 in 0.08 seconds
2019-08-26 10:41:42,148 (MainThread): Using postgres connection "master".
2019-08-26 10:41:42,148 (MainThread): On master: BEGIN
2019-08-26 10:41:42,194 (MainThread): SQL status: BEGIN in 0.05 seconds
2019-08-26 10:41:42,195 (MainThread): Using postgres connection "master".
2019-08-26 10:41:42,195 (MainThread): On master: select
      'reference' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'tlee'
    union all
    select
      'reference' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'tlee'
​
2019-08-26 10:41:42,314 (MainThread): SQL status: SELECT 261 in 0.12 seconds
2019-08-26 10:41:43,070 (MainThread): Using postgres connection "master".
2019-08-26 10:41:43,070 (MainThread): On master: --
    --
    with relation as (
        select
            pg_rewrite.ev_class as class,
            pg_rewrite.oid as id
        from pg_rewrite
    ),
    class as (
        select
            oid as id,
            relname as name,
            relnamespace as schema,
            relkind as kind
        from pg_class
    ),
    dependency as (
        select
            pg_depend.objid as id,
            pg_depend.refobjid as ref
        from pg_depend
    ),
    schema as (
        select
            pg_namespace.oid as id,
            pg_namespace.nspname as name
        from pg_namespace
        where nspname != 'information_schema' and nspname not like 'pg_%'
    ),
    referenced as (
        select
            relation.id AS id,
            referenced_class.name ,
            referenced_class.schema ,
            referenced_class.kind
        from relation
        join class as referenced_class on relation.class=referenced_class.id
        where referenced_class.kind in ('r', 'v')
    ),
    relationships as (
        select
            referenced.name as referenced_name,
            referenced.schema as referenced_schema_id,
            dependent_class.name as dependent_name,
            dependent_class.schema as dependent_schema_id,
            referenced.kind as kind
        from referenced
        join dependency on referenced.id=dependency.id
        join class as dependent_class on dependency.ref=dependent_class.id
        where
            (referenced.name != dependent_class.name or
             referenced.schema != dependent_class.schema)
    )
​
    select
        referenced_schema.name as referenced_schema,
        relationships.referenced_name as referenced_name,
        dependent_schema.name as dependent_schema,
        relationships.dependent_name as dependent_name
    from relationships
    join schema as dependent_schema on relationships.dependent_schema_id=dependent_schema.id
    join schema as referenced_schema on relationships.referenced_schema_id=referenced_schema.id
    group by referenced_schema, referenced_name, dependent_schema, dependent_name
    order by referenced_schema, referenced_name, dependent_schema, dependent_name;
2019-08-26 10:41:46,706 (MainThread): SQL status: SELECT 49106 in 3.64 seconds
2019-08-26 10:42:04,957 (MainThread): On master: ROLLBACK
2019-08-26 10:42:04,995 (MainThread): Connection 'master' was left open.
2019-08-26 10:42:04,996 (MainThread): On master: Close
2019-08-26 10:42:04,997 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x10edab110>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x1109d8910>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x1109d8cd0>]}
2019-08-26 10:42:05,196 (MainThread): Flushing usage events
2019-08-26 10:42:05,196 (MainThread): Encountered an error:
2019-08-26 10:42:05,196 (MainThread): Cache inconsistency detected: in add_link, referenced link key _ReferenceKey(database='reference', schema='tlee', identifier='cpp009_business_spend') not in cache!
2019-08-26 10:42:05,198 (MainThread): Traceback (most recent call last):
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/main.py", line 82, in main
    results, succeeded = handle_and_check(args)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/main.py", line 151, in handle_and_check
    task, res = run_from_args(parsed)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/main.py", line 216, in run_from_args
    results = task.run()
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/task/runnable.py", line 282, in run
    result = self.execute_with_hooks(selected_uids)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/task/runnable.py", line 252, in execute_with_hooks
    self.before_run(adapter, selected_uids)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/task/run.py", line 150, in before_run
    self.populate_adapter_cache(adapter)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/task/run.py", line 63, in populate_adapter_cache
    adapter.set_relations_cache(self.manifest)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/base/impl.py", line 342, in set_relations_cache
    self._relations_cache_for_schemas(manifest)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/postgres/impl.py", line 88, in _relations_cache_for_schemas
    self._link_cached_relations(manifest)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/postgres/impl.py", line 84, in _link_cached_relations
    self._link_cached_database_relations(schemas)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/postgres/impl.py", line 60, in _link_cached_database_relations
    self.cache.add_link(dependent, referenced)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/cache.py", line 296, in add_link
    self._add_link(referenced, dependent)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/adapters/cache.py", line 254, in _add_link
    .format(referenced_key)
  File "/usr/local/Cellar/dbt@0.14.0/0.14.0/libexec/lib/python3.7/site-packages/dbt/exceptions.py", line 473, in raise_cache_inconsistent
    raise InternalException('Cache inconsistency detected: {}'.format(message))
dbt.exceptions.InternalException: Cache inconsistency detected: in add_link, referenced link key _ReferenceKey(database='reference', schema='tlee', identifier='cpp009_business_spend') not in cache!
@tomtl tomtl added bug Something isn't working triage labels Aug 26, 2019
@drewbanin drewbanin removed the triage label Aug 26, 2019
@drewbanin
Copy link
Contributor

Thanks for the report @tomtl! I think we'll need to upgrade the introspective query that dbt runs to account for materialized views on PG.

@albielin
Copy link

albielin commented Sep 9, 2019

This would greatly help us - we have a ton of materialized views in our data warehouse and this is a blocker at the moment. Any suggested work arounds besides dropping the materialized views?

@drewbanin drewbanin changed the title Cache inconsistency detected on a Postgres materialized view not part of the DBT project Support Materialized Views Sep 10, 2019
@drewbanin drewbanin added this to the Louisa May Alcott milestone Sep 10, 2019
@drewbanin
Copy link
Contributor

I think the only workaround for the moment is to run dbt against a schema that does not contain any materialized views. A fix for this is going to be prioritized for dbt's next minor release.

@cmcarthur cmcarthur changed the title Support Materialized Views dbt should not crash when it sees Materialized Views Sep 25, 2019
@beckjake
Copy link
Contributor

I can't reproduce this in 0.14.0 (nor 0.14.3, nor 0.15.0a1). I'm using Postgres 10.4 server, 11.2 client because that's what I have locally, and:

$ psql -c ' create materialized view dbt_postgres_case_1698.some_matview as (select * from dbt_postgres_case_1698.some_table);'
SELECT 1

$ cat models/x.sql
select 1 as id

$ cat models/y.sql
select * from {{ ref('x') }}

$ cat models/z.sql
select * from {{ ref('y') }}

$ dbt run
Running with dbt=0.14.0-rc1
Found 3 models, 0 tests, 0 snapshots, 0 analyses, 235 macros, 0 operations, 1 seed files, 0 sources

07:38:35 | Concurrency: 2 threads (target='default')
07:38:35 |
07:38:35 | 1 of 3 START view model dbt_postgres_case_1698.x..................... [RUN]
07:38:35 | 1 of 3 OK created view model dbt_postgres_case_1698.x................ [CREATE VIEW in 0.08s]
07:38:35 | 2 of 3 START view model dbt_postgres_case_1698.y..................... [RUN]
07:38:35 | 2 of 3 OK created view model dbt_postgres_case_1698.y................ [CREATE VIEW in 0.05s]
07:38:35 | 3 of 3 START view model dbt_postgres_case_1698.z..................... [RUN]
07:38:35 | 3 of 3 OK created view model dbt_postgres_case_1698.z................ [CREATE VIEW in 0.05s]
07:38:35 |
07:38:35 | Finished running 3 view models in 0.56s.

Completed successfully

Done. PASS=3 ERROR=0 SKIP=0 TOTAL=3

@drewbanin
Copy link
Contributor

drewbanin commented Oct 15, 2019 •
edited
Loading

@beckjake I'm able to reproduce this with:

create schema test_schema;
create table test_schema.abc123 (id int);
create materialized view test_schema.some_matview as (
	select * from test_schema.abc123
); 

create view test_schema.ref_some_matview as (
	select * from test_schema.some_matview
)

After running this sql, a dbt run against the test_schema schema fails with an error like:

Cache inconsistency detected: in add_link, referenced link key _ReferenceKey(database='analytics', schema='test_schema', identifier='some_matview') not in cache!

@beckjake beckjake mentioned this issue Oct 15, 2019
Merged
beckjake added a commit that referenced this issue Oct 15, 2019
@beckjake
Merge pull request #1833 from fishtown-analytics/fix/postgres-externa…
d5824d9 
…l-materialized-views

postgres: gracefully handle materialized views (#1698)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working redshift
Projects
None yet
Milestone
Louisa May Alcott
Development

Successfully merging a pull request may close this issue.

postgres: gracefully handle materialized views (#1698) dbt-labs/dbt-core
4 participants
@beckjake @albielin @drewbanin @tomtl