From 824954322095dc3b6be6c03a441d16eb0bb0df7a Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Fri, 12 Jul 2024 14:43:57 -0400 Subject: [PATCH 1/8] setup test --- .../adapter/python_model_tests/_files.py | 21 +++++++++++++++ .../python_model_tests/test_logging.py | 27 +++++++++++++++++++ 2 files changed, 48 insertions(+) create mode 100644 tests/functional/adapter/python_model_tests/test_logging.py diff --git a/tests/functional/adapter/python_model_tests/_files.py b/tests/functional/adapter/python_model_tests/_files.py index dd69f37fa..fe19edbb4 100644 --- a/tests/functional/adapter/python_model_tests/_files.py +++ b/tests/functional/adapter/python_model_tests/_files.py @@ -46,3 +46,24 @@ def model(dbt, session): {% do return(_table) %} {% endmacro %} """ + + +MODEL__LOGGING = """ +import logging + +import snowflake.snowpark as snowpark +import snowflake.snowpark.functions as f +from snowflake.snowpark.functions import * + + +logger = logging.getLogger("dbt_logger") +logger.info("******Inside Logging module.******") + + +def model(dbt, session): + session.sql(f"ALTER SESSION SET LOG_LEVEL = INFO").collect() + logger.info("******Logging start.******") + df=session.sql(f"select current_user() as session_user, current_role() as session_role") + logger.info("******Logging End.******") + return df +""" diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py new file mode 100644 index 000000000..461eebd47 --- /dev/null +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -0,0 +1,27 @@ +from dbt.tests.util import run_dbt +import pytest + +from tests.functional.adapter.python_model_tests._files import MODEL__LOGGING + +EVENT_TABLE_SQL = """ +SELECT + RECORD['severity_text']::STRING AS log_level, + VALUE::STRING AS message, + RESOURCE_ATTRIBUTES['snow.query.id']::STRING AS query_id +FROM + DXRX_OPERATIONS.LOGGING.EVENTS +WHERE + SCOPE['name']::STRING = 'dbt_logger' +ORDER BY + 'TIMESTAMP' DESC +; +""" + + +class TestPythonModelLogging: + @pytest.fixture(scope="class") + def models(self): + return {"logging_model.py": MODEL__LOGGING} + + def test_logging(self, project): + run_dbt(["run"]) From 1ac3b2fe458b2cabb76bdbaa3fd9b39109a4c0fb Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Fri, 12 Jul 2024 19:41:11 -0400 Subject: [PATCH 2/8] establish a minimal permissions workaround for session logging --- dbt/adapters/snowflake/impl.py | 4 +++ .../adapter/python_model_tests/_files.py | 21 ----------- .../python_model_tests/test_logging.py | 36 +++++++++++-------- 3 files changed, 26 insertions(+), 35 deletions(-) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index 6854b199d..31e70f980 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -363,6 +363,8 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): if use_anonymous_sproc: proc_name = f"{identifier}__dbt_sp" python_stored_procedure = f""" +ALTER SESSION SET LOG_LEVEL = DEBUG; +ALTER SESSION SET TRACE_LEVEL = ALWAYS; WITH {proc_name} AS PROCEDURE () {common_procedure_code} CALL {proc_name}(); @@ -372,6 +374,8 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): python_stored_procedure = f""" CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; +ALTER SESSION SET LOG_LEVEL = DEBUG; +ALTER SESSION SET TRACE_LEVEL = ALWAYS; CALL {proc_name}(); """ diff --git a/tests/functional/adapter/python_model_tests/_files.py b/tests/functional/adapter/python_model_tests/_files.py index fe19edbb4..dd69f37fa 100644 --- a/tests/functional/adapter/python_model_tests/_files.py +++ b/tests/functional/adapter/python_model_tests/_files.py @@ -46,24 +46,3 @@ def model(dbt, session): {% do return(_table) %} {% endmacro %} """ - - -MODEL__LOGGING = """ -import logging - -import snowflake.snowpark as snowpark -import snowflake.snowpark.functions as f -from snowflake.snowpark.functions import * - - -logger = logging.getLogger("dbt_logger") -logger.info("******Inside Logging module.******") - - -def model(dbt, session): - session.sql(f"ALTER SESSION SET LOG_LEVEL = INFO").collect() - logger.info("******Logging start.******") - df=session.sql(f"select current_user() as session_user, current_role() as session_role") - logger.info("******Logging End.******") - return df -""" diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index 461eebd47..9792d6436 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -1,24 +1,32 @@ from dbt.tests.util import run_dbt import pytest -from tests.functional.adapter.python_model_tests._files import MODEL__LOGGING - -EVENT_TABLE_SQL = """ -SELECT - RECORD['severity_text']::STRING AS log_level, - VALUE::STRING AS message, - RESOURCE_ATTRIBUTES['snow.query.id']::STRING AS query_id -FROM - DXRX_OPERATIONS.LOGGING.EVENTS -WHERE - SCOPE['name']::STRING = 'dbt_logger' -ORDER BY - 'TIMESTAMP' DESC -; + +MODEL__LOGGING = """ +import logging + +import snowflake.snowpark as snowpark +import snowflake.snowpark.functions as f +from snowflake.snowpark.functions import * + + +logger = logging.getLogger("dbt_logger") +logger.info("******Inside Logging module.******") + + +def model(dbt, session: snowpark.Session): + logger.info("******Logging start.******") + df=session.sql(f"select current_user() as session_user, current_role() as session_role") + logger.info("******Logging End.******") + return df """ class TestPythonModelLogging: + """ + This test case addresses bug report https://github.com/dbt-labs/dbt-snowflake/issues/846 + """ + @pytest.fixture(scope="class") def models(self): return {"logging_model.py": MODEL__LOGGING} From 424ac4a78236175d9748488ee673c2d9454587be Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Fri, 12 Jul 2024 20:53:36 -0400 Subject: [PATCH 3/8] loosen logging settings --- dbt/adapters/snowflake/impl.py | 8 ++++---- .../functional/adapter/python_model_tests/test_logging.py | 7 +++++++ 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index 31e70f980..6d311f496 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -363,8 +363,8 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): if use_anonymous_sproc: proc_name = f"{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET LOG_LEVEL = DEBUG; -ALTER SESSION SET TRACE_LEVEL = ALWAYS; +ALTER SESSION SET LOG_LEVEL = INFO; +ALTER SESSION SET TRACE_LEVEL = ON_EVENT; WITH {proc_name} AS PROCEDURE () {common_procedure_code} CALL {proc_name}(); @@ -372,10 +372,10 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): else: proc_name = f"{database}.{schema}.{identifier}__dbt_sp" python_stored_procedure = f""" +ALTER SESSION SET LOG_LEVEL = INFO; +ALTER SESSION SET TRACE_LEVEL = ON_EVENT; CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; -ALTER SESSION SET LOG_LEVEL = DEBUG; -ALTER SESSION SET TRACE_LEVEL = ALWAYS; CALL {proc_name}(); """ diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index 9792d6436..617c05715 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -25,6 +25,13 @@ def model(dbt, session: snowpark.Session): class TestPythonModelLogging: """ This test case addresses bug report https://github.com/dbt-labs/dbt-snowflake/issues/846 + + -- before running: + USE ROLE ACCOUNTADMIN; + ALTER ACCOUNT UNSET LOG_LEVEL; + ALTER ACCOUNT UNSET TRACE_LEVEL; + GRANT MODIFY SESSION LOG LEVEL ON ACCOUNT TO ROLE ; + GRANT MODIFY SESSION TRACE LEVEL ON ACCOUNT TO ROLE ; """ @pytest.fixture(scope="class") From 26a6834e491452adfab470d3d919a49ecc034446 Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Fri, 12 Jul 2024 21:07:54 -0400 Subject: [PATCH 4/8] move logging level into the model --- dbt/adapters/snowflake/impl.py | 3 --- tests/functional/adapter/python_model_tests/test_logging.py | 1 + 2 files changed, 1 insertion(+), 3 deletions(-) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index 6d311f496..ef19438f3 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -363,7 +363,6 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): if use_anonymous_sproc: proc_name = f"{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET LOG_LEVEL = INFO; ALTER SESSION SET TRACE_LEVEL = ON_EVENT; WITH {proc_name} AS PROCEDURE () {common_procedure_code} @@ -372,8 +371,6 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): else: proc_name = f"{database}.{schema}.{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET LOG_LEVEL = INFO; -ALTER SESSION SET TRACE_LEVEL = ON_EVENT; CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; CALL {proc_name}(); diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index 617c05715..9228de7b0 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -11,6 +11,7 @@ logger = logging.getLogger("dbt_logger") +logger.setLevel(logging.INFO) logger.info("******Inside Logging module.******") From c55a6577d24b40eb426ad9aada0e1306ace8612d Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Fri, 12 Jul 2024 21:08:40 -0400 Subject: [PATCH 5/8] add the trace level to the persistent sp --- dbt/adapters/snowflake/impl.py | 1 + 1 file changed, 1 insertion(+) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index ef19438f3..e591862cc 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -371,6 +371,7 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): else: proc_name = f"{database}.{schema}.{identifier}__dbt_sp" python_stored_procedure = f""" +ALTER SESSION SET TRACE_LEVEL = ON_EVENT; CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; CALL {proc_name}(); From db46f51e0c8df525512f59998c223e927e0d517f Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Mon, 15 Jul 2024 17:22:00 -0400 Subject: [PATCH 6/8] reduce setting to log_level --- dbt/adapters/snowflake/impl.py | 4 ++-- tests/functional/adapter/python_model_tests/test_logging.py | 3 --- 2 files changed, 2 insertions(+), 5 deletions(-) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index e591862cc..c48fbe8d5 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -363,7 +363,7 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): if use_anonymous_sproc: proc_name = f"{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET TRACE_LEVEL = ON_EVENT; +ALTER SESSION SET LOG_LEVEL = INFO; WITH {proc_name} AS PROCEDURE () {common_procedure_code} CALL {proc_name}(); @@ -371,7 +371,7 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): else: proc_name = f"{database}.{schema}.{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET TRACE_LEVEL = ON_EVENT; +ALTER SESSION SET LOG_LEVEL = INFO; CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; CALL {proc_name}(); diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index 9228de7b0..c290c5a25 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -11,7 +11,6 @@ logger = logging.getLogger("dbt_logger") -logger.setLevel(logging.INFO) logger.info("******Inside Logging module.******") @@ -30,9 +29,7 @@ class TestPythonModelLogging: -- before running: USE ROLE ACCOUNTADMIN; ALTER ACCOUNT UNSET LOG_LEVEL; - ALTER ACCOUNT UNSET TRACE_LEVEL; GRANT MODIFY SESSION LOG LEVEL ON ACCOUNT TO ROLE ; - GRANT MODIFY SESSION TRACE LEVEL ON ACCOUNT TO ROLE ; """ @pytest.fixture(scope="class") From fc0ad59b3866f92d93abcef2c4425c743e00e769 Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Tue, 16 Jul 2024 19:25:12 -0400 Subject: [PATCH 7/8] update the workaround to use a pre-hook --- dbt/adapters/snowflake/impl.py | 2 -- .../adapter/python_model_tests/test_logging.py | 12 +++++++----- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/dbt/adapters/snowflake/impl.py b/dbt/adapters/snowflake/impl.py index c48fbe8d5..6854b199d 100644 --- a/dbt/adapters/snowflake/impl.py +++ b/dbt/adapters/snowflake/impl.py @@ -363,7 +363,6 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): if use_anonymous_sproc: proc_name = f"{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET LOG_LEVEL = INFO; WITH {proc_name} AS PROCEDURE () {common_procedure_code} CALL {proc_name}(); @@ -371,7 +370,6 @@ def submit_python_job(self, parsed_model: dict, compiled_code: str): else: proc_name = f"{database}.{schema}.{identifier}__dbt_sp" python_stored_procedure = f""" -ALTER SESSION SET LOG_LEVEL = INFO; CREATE OR REPLACE PROCEDURE {proc_name} () {common_procedure_code}; CALL {proc_name}(); diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index c290c5a25..9df1129c6 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -15,6 +15,8 @@ def model(dbt, session: snowpark.Session): + # To use: GRANT MODIFY SESSION LOG LEVEL ON ACCOUNT TO ROLE ; + dbt.config(pre_hook = 'ALTER SESSION SET LOG_LEVEL=INFO;') logger.info("******Logging start.******") df=session.sql(f"select current_user() as session_user, current_role() as session_role") logger.info("******Logging End.******") @@ -22,14 +24,14 @@ def model(dbt, session: snowpark.Session): """ +MACRO__LOGGING = """ + +""" + + class TestPythonModelLogging: """ This test case addresses bug report https://github.com/dbt-labs/dbt-snowflake/issues/846 - - -- before running: - USE ROLE ACCOUNTADMIN; - ALTER ACCOUNT UNSET LOG_LEVEL; - GRANT MODIFY SESSION LOG LEVEL ON ACCOUNT TO ROLE ; """ @pytest.fixture(scope="class") From 79bb54ad48351d5513bdcc98b919d628cfb0b43e Mon Sep 17 00:00:00 2001 From: Mike Alfare Date: Tue, 16 Jul 2024 19:29:19 -0400 Subject: [PATCH 8/8] remove unused code --- tests/functional/adapter/python_model_tests/test_logging.py | 5 ----- 1 file changed, 5 deletions(-) diff --git a/tests/functional/adapter/python_model_tests/test_logging.py b/tests/functional/adapter/python_model_tests/test_logging.py index 9df1129c6..ce767e292 100644 --- a/tests/functional/adapter/python_model_tests/test_logging.py +++ b/tests/functional/adapter/python_model_tests/test_logging.py @@ -24,11 +24,6 @@ def model(dbt, session: snowpark.Session): """ -MACRO__LOGGING = """ - -""" - - class TestPythonModelLogging: """ This test case addresses bug report https://github.com/dbt-labs/dbt-snowflake/issues/846