search

dbt-labs / dbt-postgres

Apache License 2.0
22 stars 12 forks source link

[Bug] Passing source() to a macro in the config block always returns the current model #112

Closed taherajnaFA closed 3 months ago

taherajnaFA commented 3 months ago

Is this a new bug?

Current Behavior

Upon using the source function in the config{} block on top of any model, the function always returns the current model instead of honoring the variables passed to it.

Expected Behavior

The source function should work correctly in the config block as well.

Steps To Reproduce

Created a repo to showcase this bug: https://github.com/taherajnaFA/dbt_bugs Prerequisites:

  1. Locally running postgres
  2. Python virtual env setup

Steps:

  1. install dbt-postgres using pip : pip install dbt-postgres or use the requirements.txt provided: pip install -r requirements.txt
  2. execute: dbt seed
  3. execute dbt run
  4. Observe the error thrown for trying to create an index on the current view model. Instead, it should have passed the correct source to the create_index macro.

Relevant log output

13:12:04.213858 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3F55C7A0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3F55CD10>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3F55EE70>]}

============================== 13:12:04.217746 | bd2d4629-fd28-4f5f-8ada-a010dae7f9ba ==============================
13:12:04.217746 [info ] [MainThread]: Running with dbt=1.8.1
13:12:04.218745 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'write_json': 'True', 'log_cache_events': 'False', 'partial_parse': 'True', 'cache_selected_only': 'False', 'warn_error': 'None', 'fail_fast': 'False', 'profiles_dir': 'C:\\Users\\taher.ajnawala\\IdeaProjects\\dbt_bugs', 'log_path': 'C:\\Users\\taher.ajnawala\\IdeaProjects\\dbt_bugs\\logs', 'debug': 'False', 'version_check': 'True', 'use_colors': 'True', 'use_experimental_parser': 'False', 'no_print': 'None', 'quiet': 'False', 'log_format': 'default', 'introspect': 'True', 'invocation_command': 'dbt run', 'static_parser': 'True', 'target_path': 'None', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'send_anonymous_usage_stats': 'True'}
13:12:04.412724 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'project_id', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE40122660>]}
13:12:04.457900 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'adapter_info', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3FC63DA0>]}
13:12:04.458909 [info ] [MainThread]: Registered adapter: *****=1.8.1
13:12:04.467424 [debug] [MainThread]: checksum: ebc509fb14e151ea268e89b60fd5abf912ed99129f87516462718fa2f14f4838, vars: {}, profile: , target: , version: 1.8.1
13:12:04.584887 [debug] [MainThread]: Partial parsing enabled: 0 files deleted, 0 files added, 0 files changed.
13:12:04.585392 [debug] [MainThread]: Partial parsing enabled, no changes found, skipping parsing
13:12:04.588972 [warn ] [MainThread]: [WARNING]: Configuration paths exist in your dbt_project.yml file which do not apply to any resources.
There are 1 unused configuration paths:
- models.dbt_bugs.example
13:12:04.620423 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'load_project', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE4017E6F0>]}
13:12:04.698434 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'resource_counts', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE413504A0>]}
13:12:04.698434 [info ] [MainThread]: Found 1 seed, 1 model, 1 source, 414 macros
13:12:04.699433 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'runnable_timing', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3F3266C0>]}
13:12:04.700434 [info ] [MainThread]: 
13:12:04.701433 [debug] [MainThread]: Acquiring new ***** connection 'master'
13:12:04.702434 [debug] [ThreadPool]: Acquiring new ***** connection 'list_*****'
13:12:04.769526 [debug] [ThreadPool]: Using ***** connection "list_*****"
13:12:04.770526 [debug] [ThreadPool]: On list_*****: /* {"app": "dbt", "dbt_version": "1.8.1", "profile_name": "dbt_bugs", "target_name": "dev", "connection_name": "list_*****"} */

    select distinct nspname from pg_namespace

13:12:04.770526 [debug] [ThreadPool]: Opening a new connection, currently in state init
13:12:04.801296 [debug] [ThreadPool]: SQL status: SELECT 4 in 0.0 seconds
13:12:04.802357 [debug] [ThreadPool]: On list_*****: Close
13:12:04.806741 [debug] [ThreadPool]: Acquiring new ***** connection 'list_*****_public'
13:12:04.811251 [debug] [ThreadPool]: Using ***** connection "list_*****_public"
13:12:04.812382 [debug] [ThreadPool]: On list_*****_public: BEGIN
13:12:04.812382 [debug] [ThreadPool]: Opening a new connection, currently in state init
13:12:04.838892 [debug] [ThreadPool]: SQL status: BEGIN in 0.0 seconds
13:12:04.838892 [debug] [ThreadPool]: Using ***** connection "list_*****_public"
13:12:04.839891 [debug] [ThreadPool]: On list_*****_public: /* {"app": "dbt", "dbt_version": "1.8.1", "profile_name": "dbt_bugs", "target_name": "dev", "connection_name": "list_*****_public"} */
select
      '*****' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'public'
    union all
    select
      '*****' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'public'
    union all
    select
      '*****' as database,
      matviewname as name,
      schemaname as schema,
      'materialized_view' as type
    from pg_matviews
    where schemaname ilike 'public'

13:12:04.845690 [debug] [ThreadPool]: SQL status: SELECT 4 in 0.0 seconds
13:12:04.846776 [debug] [ThreadPool]: On list_*****_public: ROLLBACK
13:12:04.847283 [debug] [ThreadPool]: On list_*****_public: Close
13:12:04.851289 [debug] [MainThread]: Using ***** connection "master"
13:12:04.852383 [debug] [MainThread]: On master: BEGIN
13:12:04.852383 [debug] [MainThread]: Opening a new connection, currently in state init
13:12:04.879610 [debug] [MainThread]: SQL status: BEGIN in 0.0 seconds
13:12:04.879610 [debug] [MainThread]: Using ***** connection "master"
13:12:04.880624 [debug] [MainThread]: On master: /* {"app": "dbt", "dbt_version": "1.8.1", "profile_name": "dbt_bugs", "target_name": "dev", "connection_name": "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 distinct
            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', 'm')
    ),
    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;
13:12:04.890146 [debug] [MainThread]: SQL status: SELECT 0 in 0.0 seconds
13:12:04.891153 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'runnable_timing', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3D911E20>]}
13:12:04.892155 [debug] [MainThread]: On master: ROLLBACK
13:12:04.892155 [debug] [MainThread]: Using ***** connection "master"
13:12:04.893201 [debug] [MainThread]: On master: BEGIN
13:12:04.893715 [debug] [MainThread]: SQL status: BEGIN in 0.0 seconds
13:12:04.893715 [debug] [MainThread]: On master: COMMIT
13:12:04.895138 [debug] [MainThread]: Using ***** connection "master"
13:12:04.895138 [debug] [MainThread]: On master: COMMIT
13:12:04.896147 [debug] [MainThread]: SQL status: COMMIT in 0.0 seconds
13:12:04.896147 [debug] [MainThread]: On master: Close
13:12:04.897358 [info ] [MainThread]: Concurrency: 1 threads (target='dev')
13:12:04.897358 [info ] [MainThread]: 
13:12:04.901369 [debug] [Thread-1 (]: Began running node model.dbt_bugs.source_bug
13:12:04.902368 [info ] [Thread-1 (]: 1 of 1 START sql view model public.source_bug .................................. [RUN]
13:12:04.903369 [debug] [Thread-1 (]: Acquiring new ***** connection 'model.dbt_bugs.source_bug'
13:12:04.903369 [debug] [Thread-1 (]: Began compiling node model.dbt_bugs.source_bug
13:12:04.914891 [info ] [Thread-1 (]: This is the source variable that is being resolved in the macro: 
13:12:04.914891 [info ] [Thread-1 (]: "*****"."public"."sample"
13:12:04.915892 [debug] [Thread-1 (]: Writing injected SQL for node "model.dbt_bugs.source_bug"
13:12:04.917365 [debug] [Thread-1 (]: Began executing node model.dbt_bugs.source_bug
13:12:04.946345 [debug] [Thread-1 (]: Using ***** connection "model.dbt_bugs.source_bug"
13:12:04.947350 [debug] [Thread-1 (]: On model.dbt_bugs.source_bug: BEGIN
13:12:04.947350 [debug] [Thread-1 (]: Opening a new connection, currently in state init
13:12:05.084432 [debug] [Thread-1 (]: SQL status: BEGIN in 0.0 seconds
13:12:05.084432 [debug] [Thread-1 (]: Using ***** connection "model.dbt_bugs.source_bug"
13:12:05.085431 [debug] [Thread-1 (]: On model.dbt_bugs.source_bug: /* {"app": "dbt", "dbt_version": "1.8.1", "profile_name": "dbt_bugs", "target_name": "dev", "node_id": "model.dbt_bugs.source_bug"} */

        CREATE INDEX IF NOT EXISTS source_bug_country_code
    ON "*****"."public"."source_bug" (country_code);

13:12:05.086431 [debug] [Thread-1 (]: Postgres adapter: Postgres error: relation "public.source_bug" does not exist

13:12:05.086431 [debug] [Thread-1 (]: On model.dbt_bugs.source_bug: ROLLBACK
13:12:05.087431 [debug] [Thread-1 (]: On model.dbt_bugs.source_bug: Close
13:12:05.091941 [debug] [Thread-1 (]: Database Error in model source_bug (models\source_bug.sql)
  relation "public.source_bug" does not exist
13:12:05.093102 [debug] [Thread-1 (]: Sending event: {'category': 'dbt', 'action': 'run_model', 'label': 'bd2d4629-fd28-4f5f-8ada-a010dae7f9ba', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3F55D4C0>]}
13:12:05.093606 [error] [Thread-1 (]: 1 of 1 ERROR creating sql view model public.source_bug ......................... [ERROR in 0.19s]
13:12:05.094612 [debug] [Thread-1 (]: Finished running node model.dbt_bugs.source_bug
13:12:05.095615 [debug] [MainThread]: Using ***** connection "master"
13:12:05.096612 [debug] [MainThread]: On master: BEGIN
13:12:05.096612 [debug] [MainThread]: Opening a new connection, currently in state closed
13:12:05.123315 [debug] [MainThread]: SQL status: BEGIN in 0.0 seconds
13:12:05.123853 [debug] [MainThread]: On master: COMMIT
13:12:05.124394 [debug] [MainThread]: Using ***** connection "master"
13:12:05.124931 [debug] [MainThread]: On master: COMMIT
13:12:05.125459 [debug] [MainThread]: SQL status: COMMIT in 0.0 seconds
13:12:05.126071 [debug] [MainThread]: On master: Close
13:12:05.126577 [debug] [MainThread]: Connection 'master' was properly closed.
13:12:05.127104 [debug] [MainThread]: Connection 'list_*****' was properly closed.
13:12:05.127104 [debug] [MainThread]: Connection 'list_*****_public' was properly closed.
13:12:05.127104 [debug] [MainThread]: Connection 'model.dbt_bugs.source_bug' was properly closed.
13:12:05.128110 [info ] [MainThread]: 
13:12:05.128110 [info ] [MainThread]: Finished running 1 view model in 0 hours 0 minutes and 0.43 seconds (0.43s).
13:12:05.129118 [debug] [MainThread]: Command end result
13:12:05.150730 [info ] [MainThread]: 
13:12:05.150730 [info ] [MainThread]: Completed with 1 error and 0 warnings:
13:12:05.151734 [info ] [MainThread]: 
13:12:05.152736 [error] [MainThread]:   Database Error in model source_bug (models\source_bug.sql)
  relation "public.source_bug" does not exist
13:12:05.152736 [info ] [MainThread]: 
13:12:05.153732 [info ] [MainThread]: Done. PASS=0 WARN=0 ERROR=1 SKIP=0 TOTAL=1
13:12:05.154730 [debug] [MainThread]: Command `dbt run` failed at 13:12:05.154730 after 1.04 seconds
13:12:05.154730 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3FAEA840>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3FE65340>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x000001EE3FE655B0>]}
13:12:05.155730 [debug] [MainThread]: Flushing usage events

Environment

- OS: Windows 11 Pro 23H2
- Python: 3.12.2
- dbt-postgres: 1.8.1

Additional Context

No response

taherajnaFA commented 3 months ago

This is an issue caused when DBT tries to execute the script during the "compilation" phase. Adding the below blocks fixes the issue:

{% macro sample_macro(variable) %}
{% if execute %}
--Macro Here
{% endif %}
{% endmacro %}