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.

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

[ADAP-1046] [CT-3418] [Bug] dbt python model logging not working with snowflake #846

Closed
2 tasks done
manishkundu opened this issue Nov 24, 2023 · 3 comments · May be fixed by #1115
Closed
2 tasks done

[ADAP-1046] [CT-3418] [Bug] dbt python model logging not working with snowflake #846

manishkundu opened this issue Nov 24, 2023 · 3 comments · May be fixed by #1115
Assignees
Labels
bug Something isn't working python_models

Comments

@manishkundu
Copy link

manishkundu commented Nov 24, 2023

Is this a new bug in dbt-core?

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

Current Behavior

dbt python model logging statement not able to put logs inside snowflake event table.

Model Name: Logging_test.py
Code:

import snowflake.snowpark as snowpark
import snowflake.snowpark.functions as f
from snowflake.snowpark.functions import *
import logging
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

Expected Behavior

dbt model should put log in event table

Steps To Reproduce

  1. Set snowflake event table : https://docs.snowflake.com/en/developer-guide/logging-tracing/event-table-setting-up
  2. Set connection param in dbt profile.yml file
  3. run the dbt python model : dbt run -model logging_test
  4. check event table in snowflake setup in step1
    SELECT
        RECORD['severity_text']::STRING log_level ,
        VALUE::STRING message ,
        RESOURCE_ATTRIBUTES['snow.query.id']::STRING query_id
    FROM
        DXRX_OPERATIONS.LOGGING.EVENTS
    WHERE
        SCOPE['name']::STRING = 'dbt_logger'
    ORDER BY
        "TIMESTAMP" DESC;
  5. Check query history in snowsight and get the dbt generated store procedure (Sql query start with WITH logging_test__dbt_sp AS PROCEDURE ())
  6. Execute the procedure from snowsight and wait for few minute
  7. Execute the step 4 query again , it will show you logs generated by Snowsight query id
  8. dbt generated query id logs missing from event table ----(it should be there )

Relevant log output

No response

Environment

- OS: window
- Python: 3.8
- dbt:1.7.2

Which database adapter are you using with dbt?

snowflake

Additional Context

While executing the dbt generated store procedure from snowsight, it's working fine and insert logs in event log table

@manishkundu manishkundu added bug Something isn't working triage labels Nov 24, 2023
@github-actions github-actions bot changed the title [Bug] dbt python model logging not working with snowflake [CT-3418] [Bug] dbt python model logging not working with snowflake Nov 24, 2023
@dbeatty10 dbeatty10 transferred this issue from dbt-labs/dbt-core Nov 27, 2023
@github-actions github-actions bot changed the title [CT-3418] [Bug] dbt python model logging not working with snowflake [ADAP-1046] [CT-3418] [Bug] dbt python model logging not working with snowflake Nov 27, 2023
@wenbaolicat
Copy link

any progress?

@mikealfare
Copy link
Contributor

mikealfare commented Jul 12, 2024

@manishkundu @wenbaolicat I've tried quite a lot of combinations of settings and I believe this comes down to the settings on TRACE LEVEL. This setting may be defaulted to OFF for the dbt runner, but is on for your account or your session. I'll put together a minimal reproduction and attach it as a PR, but in the meantime, could you please verify that TRACE_LEVEL is not set to OFF somehow? Alternatively, if you have permissions on your account, could you run ALTER ACCOUNT SET TRACE LEVEL = ALWAYS; and re-run your example to see if the issue persists?

@mikealfare
Copy link
Contributor

@manishkundu @wenbaolicat It looks like the TRACE_LEVEL parameter was not the issue. Apparently it takes well over a minute for the event table to reflect logs and I must have been picking up logs from prior settings. The issue seems to be that setting LOG_LEVEL within the stored procedure creation does not work. However, I was able to get it to work if I used a pre-hook as this runs prior to the stored procedure:

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):
    # To use: GRANT MODIFY SESSION LOG LEVEL ON ACCOUNT TO ROLE <DBT_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.******")
    return df

Please let me know if this is still not working for you.

@mikealfare mikealfare closed this as not planned Won't fix, can't repro, duplicate, stale Jul 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working python_models
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants