[Bug] Error when referencing env_vars in on-run-* hooks after upgrade to v1.0.0

[rodik]

Is there an existing issue for this?

• I have searched the existing issues

Current Behavior

After upgrade to dbt 1.0.0 adding on-run-* hook events that reference environment variables throws an error; ie adding

on-run-start:
    - "{{ log(env_var('TERM_PROGRAM'), info=True) }}"

Will result with:

Encountered an error:
'{project_name}://./dbt_project.yml'

Expected Behavior

Earlier versions of dbt supported using environment variables in on-run-* hooks.

Steps To Reproduce

1. init a new repo and setup a working profile
2. edit dbt_project.yml and add "{{ log(env_var('TERM_PROGRAM'), info=True) }}" to on-run-start:
3. run dbt compile or dbt run command
4. get error

Relevant log output

Nothing relevant found in dbt.log:

============================== 2021-12-20 15:41:53.886920 | 0da9e948-8114-4415-8872-4cb899975bed ==============================
15:41:53.886920 [info ] [MainThread]: Running with dbt=1.0.0
15:41:53.887576 [debug] [MainThread]: running dbt with arguments Namespace(cls=<class 'dbt.task.run.RunTask'>, debug=None, defer=None, event_buffer_size=None, exclude=None, fail_fast=None, full_refresh=False, log_cache_events=False, log_format=None, partial_parse=None, printer_width=None, profile=None, profiles_dir='/home/frodik/.dbt', project_dir=None, record_timing_info=None, rpc_method='run', select=['my_first_dbt_model'], selector_name=None, send_anonymous_usage_stats=None, single_threaded=False, state=None, static_parser=None, target=None, threads=None, use_colors=None, use_experimental_parser=None, vars='{}', version_check=None, warn_error=None, which='run', write_json=None)
15:41:53.887936 [debug] [MainThread]: Tracking: tracking
15:41:53.888459 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd3bbc4d0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd3bbc3d0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd3bbc490>]}
15:41:53.914767 [info ] [MainThread]: Unable to do partial parsing because a project config has changed
15:41:53.915575 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'partial_parser', 'label': '0da9e948-8114-4415-8872-4cb899975bed', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd3b4df90>]}
15:41:53.932010 [debug] [MainThread]: Parsing macros/production_targets.sql
15:41:53.932924 [debug] [MainThread]: Parsing macros/generate_database_name.sql
15:41:53.935178 [debug] [MainThread]: Parsing macros/adapters.sql
15:41:53.988923 [debug] [MainThread]: Parsing macros/catalog.sql
15:41:53.992221 [debug] [MainThread]: Parsing macros/materializations/snapshot.sql
15:41:53.994014 [debug] [MainThread]: Parsing macros/materializations/merge.sql
15:41:53.999244 [debug] [MainThread]: Parsing macros/materializations/incremental.sql
15:41:54.011414 [debug] [MainThread]: Parsing macros/materializations/table.sql
15:41:54.015346 [debug] [MainThread]: Parsing macros/materializations/view.sql
15:41:54.016983 [debug] [MainThread]: Parsing macros/materializations/seed.sql
15:41:54.024422 [debug] [MainThread]: Parsing macros/adapters/columns.sql
15:41:54.035896 [debug] [MainThread]: Parsing macros/adapters/relation.sql
15:41:54.048334 [debug] [MainThread]: Parsing macros/adapters/persist_docs.sql
15:41:54.053607 [debug] [MainThread]: Parsing macros/adapters/freshness.sql
15:41:54.057335 [debug] [MainThread]: Parsing macros/adapters/indexes.sql
15:41:54.062994 [debug] [MainThread]: Parsing macros/adapters/schema.sql
15:41:54.070124 [debug] [MainThread]: Parsing macros/adapters/metadata.sql
15:41:54.081231 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_schema.sql
15:41:54.085886 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_database.sql
15:41:54.087841 [debug] [MainThread]: Parsing macros/get_custom_name/get_custom_alias.sql
15:41:54.089636 [debug] [MainThread]: Parsing macros/etc/datetime.sql
15:41:54.100324 [debug] [MainThread]: Parsing macros/etc/statement.sql
15:41:54.105840 [debug] [MainThread]: Parsing macros/generic_test_sql/unique.sql
15:41:54.106684 [debug] [MainThread]: Parsing macros/generic_test_sql/not_null.sql
15:41:54.107482 [debug] [MainThread]: Parsing macros/generic_test_sql/relationships.sql
15:41:54.108670 [debug] [MainThread]: Parsing macros/generic_test_sql/accepted_values.sql
15:41:54.110343 [debug] [MainThread]: Parsing macros/materializations/configs.sql
15:41:54.113391 [debug] [MainThread]: Parsing macros/materializations/hooks.sql
15:41:54.120316 [debug] [MainThread]: Parsing macros/materializations/tests/where_subquery.sql
15:41:54.123387 [debug] [MainThread]: Parsing macros/materializations/tests/helpers.sql
15:41:54.125961 [debug] [MainThread]: Parsing macros/materializations/tests/test.sql
15:41:54.131852 [debug] [MainThread]: Parsing macros/materializations/seeds/helpers.sql
15:41:54.150308 [debug] [MainThread]: Parsing macros/materializations/seeds/seed.sql
15:41:54.158306 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot_merge.sql
15:41:54.160212 [debug] [MainThread]: Parsing macros/materializations/snapshots/snapshot.sql
15:41:54.173872 [debug] [MainThread]: Parsing macros/materializations/snapshots/strategies.sql
15:41:54.193808 [debug] [MainThread]: Parsing macros/materializations/snapshots/helpers.sql
15:41:54.206852 [debug] [MainThread]: Parsing macros/materializations/models/incremental/on_schema_change.sql
15:41:54.224285 [debug] [MainThread]: Parsing macros/materializations/models/incremental/merge.sql
15:41:54.237616 [debug] [MainThread]: Parsing macros/materializations/models/incremental/incremental.sql
15:41:54.250053 [debug] [MainThread]: Parsing macros/materializations/models/incremental/is_incremental.sql
15:41:54.252190 [debug] [MainThread]: Parsing macros/materializations/models/incremental/column_helpers.sql
15:41:54.256979 [debug] [MainThread]: Parsing macros/materializations/models/view/create_or_replace_view.sql
15:41:54.259853 [debug] [MainThread]: Parsing macros/materializations/models/view/helpers.sql
15:41:54.261462 [debug] [MainThread]: Parsing macros/materializations/models/view/view.sql
15:41:54.269453 [debug] [MainThread]: Parsing macros/materializations/models/view/create_view_as.sql
15:41:54.272266 [debug] [MainThread]: Parsing macros/materializations/models/table/create_table_as.sql
15:41:54.275753 [debug] [MainThread]: Parsing macros/materializations/models/table/table.sql
15:41:54.284280 [debug] [MainThread]: Parsing tests/generic/builtin.sql
15:41:54.550135 [debug] [MainThread]: 1699: static parser successfully parsed example/my_second_dbt_model.sql
15:41:54.563110 [debug] [MainThread]: 1699: static parser successfully parsed example/my_first_dbt_model.sql
15:41:54.583108 [debug] [MainThread]: Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd2ada850>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd2ada2d0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x7fcfd2ada890>]}

Environment

# 1st attempt
dbt version: 1.0.0
python version: 3.7.6
os info: Linux-5.10.60.1-microsoft-standard-WSL2-x86_64-with-debian-bullseye-sid

Configuration:
  profiles.yml file [OK found and valid]
  dbt_project.yml file [OK found and valid]


# 2nd attempt
dbt version: 1.0.0
python version: 3.9.9
os info: Linux-5.10.60.1-microsoft-standard-WSL2-x86_64-with-glibc2.31

Configuration:
  profiles.yml file [OK found and valid]
  dbt_project.yml file [OK found and valid]

What database are you using dbt with?

snowflake

Additional Context

Slack discussion on issue.

[gshank]

Thanks for reporting this! Fix should be pretty quick.