search

snowflakedb / snowflake-sqlalchemy

Snowflake SQLAlchemy
https://pypi.python.org/pypi/snowflake-sqlalchemy/
Apache License 2.0
231 stars 152 forks source link

SNOW-892284: Boolean URL connection parameters are passed down to the driver as strings #438

Closed saulbein closed 10 months ago

saulbein commented 1 year ago

Please answer these questions before submitting your issue. Thanks!

  1. What version of Python are you using?

    Python 3.8.16 (default, Feb 6 2023, 12:05:53) [GCC 12.2.1 20230111]

  2. What operating system and processor architecture are you using?

    Linux-6.1.38-1-MANJARO-x86_64-with-glibc2.34

  3. What are the component versions in the environment (pip freeze)?

    Using latest master version (de68d86) of this repository with it's defined dependencies:

    asn1crypto==1.5.1
certifi==2023.7.22
cffi==1.15.1
charset-normalizer==3.2.0
cryptography==41.0.3
filelock==3.12.2
greenlet==2.0.2
idna==3.4
oscrypto==1.3.0
packaging==23.1
platformdirs==3.8.1
pycparser==2.21
pycryptodomex==3.18.0
PyJWT==2.8.0
pyOpenSSL==23.2.0
pytz==2023.3
requests==2.31.0
snowflake-connector-python==3.1.0
-e git+ssh://git@github.com/snowflakedb/snowflake-sqlalchemy.git@de68d864af14200643b74625db4480db87c92172#egg=snowflake_sqlalchemy
sortedcontainers==2.4.0
SQLAlchemy==1.4.49
tomlkit==0.12.1
typing_extensions==4.7.1
urllib3==1.26.16

  4. What did you do?

    Opened the same connection multiple times with client_store_temporary_credential=True and authenticator="externalbrowser", which then prompted multiple times for authentication.

    Code to reproduce (note that this requires some environment variables):

    import os
# need to set these up in advance
account = os.environ["SNOWFLAKE_ACCOUNT"]
user = os.environ["SNOWFLAKE_USER"]
role = os.environ["SNOWFLAKE_ROLE"]
warehouse = os.environ["SNOWFLAKE_WAREHOUSE"]
database = os.environ["SNOWFLAKE_DATABASE"]
config = {"account": account, "user": user, "role": role, "warehouse": warehouse, "database": database, "authenticator": "externalbrowser", "client_store_temporary_credential": True}
from snowflake.sqlalchemy import URL
url = URL(**config)
import sqlalchemy as sa
engine = sa.create_engine(url)
import logging
logging.basicConfig(level=logging.DEBUG, format='%(asctime)s - %(threadName)s %(filename)s:%(lineno)d - %(funcName)s() - %(levelname)s - %(message)s')
# prompts for auth
engine.connect()
# prompts for auth.. again?
engine.connect()

  5. What did you expect to see?

    I expected the credentials to be cached and to not be asked for authentication the second time.

  6. Can you set logging to DEBUG and collect the logs?

    First connect (second connect is basically the same):

    2023-08-14 13:16:53,427 - MainThread connection.py:282 - __init__() - INFO - Snowflake Connector for Python Version: 3.0.3, Python Version: 3.8.16, Platform: Linux-6.1.38-1-MANJARO-x86_64-with-glibc2.34
2023-08-14 13:16:53,427 - MainThread connection.py:541 - connect() - DEBUG - connect
2023-08-14 13:16:53,427 - MainThread connection.py:852 - __config() - DEBUG - __config
2023-08-14 13:16:53,427 - MainThread connection.py:989 - __config() - INFO - This connection is in OCSP Fail Open Mode. TLS Certificates would be checked for validity and revocation status. Any other Certificate Revocation related exceptions or OCSP Responder failures would be disregarded in favor of connectivity.
2023-08-14 13:16:53,427 - MainThread connection.py:1007 - __config() - INFO - Setting use_openssl_only mode to False
2023-08-14 13:16:53,427 - MainThread converter.py:150 - __init__() - DEBUG - use_numpy: False
2023-08-14 13:16:53,427 - MainThread connection.py:734 - __open_connection() - DEBUG - REST API object was created: ig78751.eu-west-1.snowflakecomputing.com:443
2023-08-14 13:16:53,428 - MainThread _auth.py:638 - read_temporary_credential_file() - DEBUG - Failed to read a credential file. The file may notexists: file=[~/.cache/snowflake/temporary_credential.json], err=[[Errno 2] No such file or directory: '~/.cache/snowflake/temporary_credential.json']
2023-08-14 13:16:53,428 - MainThread webbrowser.py:113 - prepare() - DEBUG - authenticating by Web Browser
2023-08-14 13:16:53,428 - MainThread webbrowser.py:136 - prepare() - DEBUG - step 1: query GS to obtain SSO url
2023-08-14 13:16:53,428 - MainThread webbrowser.py:401 - _get_sso_url() - DEBUG - account=ig78751, authenticator=EXTERNALBROWSER, user=redacted
2023-08-14 13:16:53,429 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2023-08-14 13:16:53,429 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2023-08-14 13:16:53,429 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-08-14 13:16:53,429 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: 120, retry cnt: 1
2023-08-14 13:16:53,429 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: dfd97dae-848d-4041-a62d-ec6ef9769ad7
2023-08-14 13:16:53,429 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-08-14 13:16:53,431 - MainThread connectionpool.py:1003 - _new_conn() - DEBUG - Starting new HTTPS connection (1): ig78751.eu-west-1.snowflakecomputing.com:443
2023-08-14 13:16:53,771 - MainThread _api.py:216 - acquire() - DEBUG - Attempting to acquire lock 140079934646016 on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,771 - MainThread _api.py:219 - acquire() - DEBUG - Lock 140079934646016 acquired on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,772 - MainThread _api.py:216 - acquire() - DEBUG - Attempting to acquire lock 140079933994992 on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,772 - MainThread _api.py:225 - acquire() - DEBUG - Timeout on acquiring lock 140079933994992 on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,772 - MainThread cache.py:545 - _save() - DEBUG - acquiring ~/.cache/snowflake/ocsp_response_validation_cache.lock timed out, skipping saving...
2023-08-14 13:16:53,774 - MainThread _api.py:249 - release() - DEBUG - Attempting to release lock 140079934646016 on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,774 - MainThread _api.py:252 - release() - DEBUG - Lock 140079934646016 released on ~/.cache/snowflake/ocsp_response_validation_cache.lock
2023-08-14 13:16:53,774 - MainThread ocsp_snowflake.py:485 - reset_cache_dir() - DEBUG - cache directory: ~/.cache/snowflake
2023-08-14 13:16:53,826 - MainThread ssl_wrap_socket.py:81 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None
2023-08-14 13:16:53,826 - MainThread ocsp_snowflake.py:523 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file://~/.cache/snowflake/ocsp_response_cache.json
2023-08-14 13:16:53,826 - MainThread ocsp_snowflake.py:526 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 190
2023-08-14 13:16:53,826 - MainThread ocsp_snowflake.py:333 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP response cache server is enabled: http://ocsp.snowflakecomputing.com/ocsp_response_cache.json
2023-08-14 13:16:53,826 - MainThread ocsp_snowflake.py:346 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None
2023-08-14 13:16:53,826 - MainThread ocsp_snowflake.py:956 - validate() - DEBUG - validating certificate: ig78751.eu-west-1.snowflakecomputing.com
2023-08-14 13:16:53,827 - MainThread ocsp_asn1crypto.py:435 - extract_certificate_chain() - DEBUG - # of certificates: 4
2023-08-14 13:16:53,827 - MainThread ocsp_asn1crypto.py:440 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('common_name', '*.eu-west-1.snowflakecomputing.com')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon RSA 2048 M01')])
2023-08-14 13:16:53,828 - MainThread ocsp_asn1crypto.py:440 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon RSA 2048 M01')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon Root CA 1')])
2023-08-14 13:16:53,828 - MainThread ocsp_asn1crypto.py:440 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon Root CA 1')]), issuer: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Arizona'), ('locality_name', 'Scottsdale'), ('organization_name', 'Starfield Technologies, Inc.'), ('common_name', 'Starfield Services Root Certificate Authority - G2')])
2023-08-14 13:16:53,829 - MainThread ocsp_asn1crypto.py:440 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Arizona'), ('locality_name', 'Scottsdale'), ('organization_name', 'Starfield Technologies, Inc.'), ('common_name', 'Starfield Services Root Certificate Authority - G2')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Starfield Technologies, Inc.'), ('organizational_unit_name', 'Starfield Class 2 Certification Authority')])
2023-08-14 13:16:53,831 - MainThread ocsp_asn1crypto.py:114 - read_cert_bundle() - DEBUG - reading certificate bundle: ~/code/snowflake-sqlalchemy/.direnv/python-3.8.16/lib/python3.8/site-packages/certifi/cacert.pem
2023-08-14 13:16:53,845 - MainThread ocsp_asn1crypto.py:463 - create_pair_issuer_subject() - DEBUG - not found issuer_der: OrderedDict([('country_name', 'US'), ('organization_name', 'Starfield Technologies, Inc.'), ('organizational_unit_name', 'Starfield Class 2 Certification Authority')])
2023-08-14 13:16:53,847 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('common_name', '*.eu-west-1.snowflakecomputing.com')])
2023-08-14 13:16:53,848 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-09-15 19:41:06+00:00
2023-08-14 13:16:53,849 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon RSA 2048 M01')])
2023-08-14 13:16:53,850 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-09-15 19:45:34+00:00
2023-08-14 13:16:53,851 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon Root CA 1')])
2023-08-14 13:16:53,852 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2024-06-06 12:00:00+00:00
2023-08-14 13:16:53,853 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Arizona'), ('locality_name', 'Scottsdale'), ('organization_name', 'Starfield Technologies, Inc.'), ('common_name', 'Starfield Services Root Certificate Authority - G2')])
2023-08-14 13:16:53,855 - MainThread ocsp_snowflake.py:1013 - _validate() - DEBUG - ok
2023-08-14 13:16:53,930 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://ig78751.eu-west-1.snowflakecomputing.com:443 "POST /session/authenticator-request?request_guid=dfd97dae-848d-4041-a62d-ec6ef9769ad7 HTTP/1.1" 200 933
2023-08-14 13:16:53,931 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-08-14 13:16:53,931 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-08-14 13:16:53,931 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-08-14 13:16:53,932 - MainThread webbrowser.py:141 - prepare() - DEBUG - Validate SSO URL
Initiating login request with your identity provider. A browser window should have opened for you to complete the login. If you can't see it, check existing browser windows, or your OS settings. Press CTRL+C to abort and try again...
2023-08-14 13:16:53,932 - MainThread webbrowser.py:159 - prepare() - DEBUG - step 2: open a browser
Going to open: <redacted URL> to authenticate...
2023-08-14 13:16:54,069 - MainThread webbrowser.py:184 - prepare() - DEBUG - step 3: accept SAML token
2023-08-14 13:16:56,615 - MainThread webbrowser.py:364 - _get_user_agent() - DEBUG - User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:109.0) Gecko/20100101 Firefox/115.0
2023-08-14 13:16:56,615 - MainThread _auth.py:171 - authenticate() - DEBUG - authenticate
2023-08-14 13:16:56,615 - MainThread _auth.py:201 - authenticate() - DEBUG - assertion content: <redacted assertion>
2023-08-14 13:16:56,615 - MainThread _auth.py:204 - authenticate() - DEBUG - account=ig78751, user=redacted, database=redacted, schema=None, warehouse=redacted, role=redacted, request_id=3eff3074-3104-49d5-866d-9087bb66ed4d
2023-08-14 13:16:56,615 - MainThread _auth.py:237 - authenticate() - DEBUG - body['data']: {'CLIENT_APP_ID': 'SnowflakeSQLAlchemy', 'CLIENT_APP_VERSION': '1.4.7', 'SVN_REVISION': None, 'ACCOUNT_NAME': 'ig78751', 'LOGIN_NAME': 'redacted', 'CLIENT_ENVIRONMENT': {'APPLICATION': 'SnowflakeSQLAlchemy', 'OS': 'Linux', 'OS_VERSION': 'Linux-6.1.38-1-MANJARO-x86_64-with-glibc2.34', 'PYTHON_VERSION': '3.8.16', 'PYTHON_RUNTIME': 'CPython', 'PYTHON_COMPILER': 'GCC 12.2.1 20230111', 'OCSP_MODE': 'FAIL_OPEN', 'TRACING': 10, 'LOGIN_TIMEOUT': 120, 'NETWORK_TIMEOUT': None}, 'AUTHENTICATOR': 'EXTERNALBROWSER', 'TOKEN': 'redacted', 'PROOF_KEY': 'redacted', 'SESSION_PARAMETERS': {'AUTOCOMMIT': False, 'CLIENT_PREFETCH_THREADS': 4, 'CLIENT_STORE_TEMPORARY_CREDENTIAL': 'True'}}
2023-08-14 13:16:56,616 - MainThread _auth.py:247 - authenticate() - DEBUG - Timeout set to 120
2023-08-14 13:16:56,616 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-08-14 13:16:56,616 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: 120, retry cnt: 1
2023-08-14 13:16:56,616 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: b1b9ef77-61cc-4812-9d28-a9bebbcde20b
2023-08-14 13:16:56,616 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-08-14 13:16:56,788 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://ig78751.eu-west-1.snowflakecomputing.com:443 "POST /session/v1/login-request?request_id=3eff3074-3104-49d5-866d-9087bb66ed4d&databaseName=redacted&warehouse=redacted&roleName=redacted&request_guid=b1b9ef77-61cc-4812-9d28-a9bebbcde20b HTTP/1.1" 200 1572
2023-08-14 13:16:56,789 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-08-14 13:16:56,789 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-08-14 13:16:56,789 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-08-14 13:16:56,789 - MainThread _auth.py:366 - authenticate() - DEBUG - completed authentication
2023-08-14 13:16:56,789 - MainThread _auth.py:413 - authenticate() - DEBUG - token = ******
2023-08-14 13:16:56,789 - MainThread _auth.py:416 - authenticate() - DEBUG - master_token = ******
2023-08-14 13:16:56,789 - MainThread _auth.py:420 - authenticate() - DEBUG - id_token = NULL
2023-08-14 13:16:56,789 - MainThread _auth.py:424 - authenticate() - DEBUG - mfa_token = NULL
2023-08-14 13:16:56,789 - MainThread _auth.py:516 - _write_temporary_credential() - DEBUG - no credential is given when try to store temporary credential
2023-08-14 13:16:56,791 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-08-14 13:16:56,791 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-08-14 13:16:56,791 - MainThread connection.py:1317 - _process_params_dict() - DEBUG - parameters: {}
2023-08-14 13:16:56,791 - MainThread cursor.py:592 - _preprocess_pyformat_query() - DEBUG - binding: [select current_database(), current_schema();] with input=[{}], processed=[{}]
2023-08-14 13:16:56,791 - MainThread cursor.py:800 - execute() - INFO - query: [select current_database(), current_schema();]
2023-08-14 13:16:56,791 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 1
2023-08-14 13:16:56,791 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 96ec88ec-b3ab-416d-bd94-874aa4aa80e5
2023-08-14 13:16:56,791 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [select current_database(), current_schema();]
2023-08-14 13:16:56,791 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-08-14 13:16:56,791 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-08-14 13:16:56,791 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[select current_database(), current_schema();], sequence_id=[1], is_file_transfer=[False]
2023-08-14 13:16:56,791 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-08-14 13:16:56,791 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-08-14 13:16:56,791 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: dc25f716-e2f5-4882-a20a-828b24870def
2023-08-14 13:16:56,792 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-08-14 13:16:56,887 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://ig78751.eu-west-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=96ec88ec-b3ab-416d-bd94-874aa4aa80e5&request_guid=dc25f716-e2f5-4882-a20a-828b24870def HTTP/1.1" 200 1735
2023-08-14 13:16:56,888 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-08-14 13:16:56,889 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-08-14 13:16:56,889 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-08-14 13:16:56,889 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01ae4cc8-0302-bc59-0051-ed020bc495c7
2023-08-14 13:16:56,889 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01ae4cc8-0302-bc59-0051-ed020bc495c7
2023-08-14 13:16:56,890 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-08-14 13:16:56,890 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-08-14 13:16:56,890 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-08-14 13:16:56,890 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: arrow
2023-08-14 13:16:56,890 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2023-08-14 13:16:56,892 - MainThread arrow_iterator.cpython-38-x86_64-linux-gnu.so:0 - __cinit__() - DEBUG - Batches read: 1
2023-08-14 13:16:56,892 - MainThread CArrowIterator.cpp:16 - CArrowIterator() - DEBUG - Arrow BatchSize: 1
2023-08-14 13:16:56,893 - MainThread CArrowChunkIterator.cpp:50 - CArrowChunkIterator() - DEBUG - Arrow chunk info: batchCount 1, columnCount 2, use_numpy: 0
2023-08-14 13:16:56,893 - MainThread result_set.py:58 - result_set_iterator() - DEBUG - beginning to schedule result batch downloads
2023-08-14 13:16:56,893 - MainThread CArrowChunkIterator.cpp:74 - next() - DEBUG - Current batch index: 0, rows in current batch: 1
2023-08-14 13:16:56,893 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-08-14 13:16:56,893 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-08-14 13:16:56,894 - MainThread cursor.py:592 - _preprocess_pyformat_query() - DEBUG - binding: [ROLLBACK] with input=[None], processed=[{}]
2023-08-14 13:16:56,894 - MainThread cursor.py:800 - execute() - INFO - query: [ROLLBACK]
2023-08-14 13:16:56,894 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 2
2023-08-14 13:16:56,894 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 89dcbd27-d174-409f-b02d-f6b3036913aa
2023-08-14 13:16:56,894 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [ROLLBACK]
2023-08-14 13:16:56,894 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-08-14 13:16:56,894 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-08-14 13:16:56,894 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[ROLLBACK], sequence_id=[2], is_file_transfer=[False]
2023-08-14 13:16:56,894 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-08-14 13:16:56,894 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-08-14 13:16:56,895 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: 5d02e00d-81e3-4a81-b920-c2e565160fa0
2023-08-14 13:16:56,895 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-08-14 13:16:56,976 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://ig78751.eu-west-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=89dcbd27-d174-409f-b02d-f6b3036913aa&request_guid=5d02e00d-81e3-4a81-b920-c2e565160fa0 HTTP/1.1" 200 1199
2023-08-14 13:16:56,977 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-08-14 13:16:56,977 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool 'ig78751.eu-west-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-08-14 13:16:56,977 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-08-14 13:16:56,977 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01ae4cc8-0302-ba23-0051-ed020bc4a3ab
2023-08-14 13:16:56,977 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01ae4cc8-0302-ba23-0051-ed020bc4a3ab
2023-08-14 13:16:56,977 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-08-14 13:16:56,977 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-08-14 13:16:56,977 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-08-14 13:16:56,977 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-08-14 13:16:56,977 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-08-14 13:16:56,977 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1

    Notable log messages:

    1. CLIENT_STORE_TEMPORARY_CREDENTIAL set to string of True rather than a boolean: 
      _auth.py:237 - authenticate() - DEBUG - body['data']: {<ommitted for brevity>, 'SESSION_PARAMETERS': {'AUTOCOMMIT': False, 'CLIENT_PREFETCH_THREADS': 4, 'CLIENT_STORE_TEMPORARY_CREDENTIAL': 'True'}}
    2. Failing to get the id token: 
      2023-08-14 13:16:56,789 - MainThread _auth.py:366 - authenticate() - DEBUG - completed authentication
2023-08-14 13:16:56,789 - MainThread _auth.py:413 - authenticate() - DEBUG - token = ******
2023-08-14 13:16:56,789 - MainThread _auth.py:416 - authenticate() - DEBUG - master_token = ******
2023-08-14 13:16:56,789 - MainThread _auth.py:420 - authenticate() - DEBUG - id_token = NULL  # <---- this shouldn't be NULL
2023-08-14 13:16:56,789 - MainThread _auth.py:424 - authenticate() - DEBUG - mfa_token = NULL
    3. Failing to write to the cache because the credential wasn't loaded: 
      2023-08-14 13:16:56,789 - MainThread _auth.py:516 - _write_temporary_credential() - DEBUG - no credential is given when try to store temporary credential

  7. Root cause

    This problem is caused by incorrect boolean handling in this part of the SnowflakeDialect: https://github.com/snowflakedb/snowflake-sqlalchemy/blob/de68d864af14200643b74625db4480db87c92172/src/snowflake/sqlalchemy/snowdialect.py#L202-L233 Line 229 updates the properties based on the query parameters, but the query parameters at that point are converted by the URL class into strings, so they get set as strings as well. By adding this bit of hacky code after line 229, I got the credential caching working, but this would affect all boolean parameters so a more generic solution should be made:

    opts["client_store_temporary_credential"] = (
   opts.get("client_store_temporary_credential") == "True" or False
)
radrichard commented 1 year ago

You sir are my hero.

sfc-gh-stan commented 1 year ago

Thank you for reporting this issue and submitting a fix 🙂 . I will look at the PR today.

saulbein commented 1 year ago

Any updates?