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

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

Closed
saulbein opened this issue Aug 14, 2023 · 3 comments
Labels
bug Something isn't working needs triage

Comments

@saulbein
Copy link
Contributor

saulbein commented Aug 14, 2023

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'}}
    
    1. 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
    
    1. 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:

    def create_connect_args(self, url):
    opts = url.translate_connect_args(username="user")
    if "database" in opts:
    name_spaces = [unquote_plus(e) for e in opts["database"].split("/")]
    if len(name_spaces) == 1:
    pass
    elif len(name_spaces) == 2:
    opts["database"] = name_spaces[0]
    opts["schema"] = name_spaces[1]
    else:
    raise sa_exc.ArgumentError(
    f"Invalid name space is specified: {opts['database']}"
    )
    if (
    "host" in opts
    and ".snowflakecomputing.com" not in opts["host"]
    and not opts.get("port")
    ):
    opts["account"] = opts["host"]
    if "." in opts["account"]:
    # remove region subdomain
    opts["account"] = opts["account"][0 : opts["account"].find(".")]
    # remove external ID
    opts["account"] = opts["account"].split("-")[0]
    opts["host"] = opts["host"] + ".snowflakecomputing.com"
    opts["port"] = "443"
    opts["autocommit"] = False # autocommit is disabled by default
    opts.update(url.query)
    self._cache_column_metadata = (
    opts.get("cache_column_metadata", "false").lower() == "true"
    )
    return ([], opts)

    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
    )
@saulbein saulbein added bug Something isn't working needs triage labels Aug 14, 2023
@github-actions github-actions bot changed the title Boolean URL connection parameters are passed down to the driver as strings SNOW-892284: Boolean URL connection parameters are passed down to the driver as strings Aug 14, 2023
@radrichard
Copy link

You sir are my hero.

@sfc-gh-stan
Copy link
Collaborator

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

@saulbein
Copy link
Contributor Author

Any updates?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working needs triage
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants