snowflake-sqlalchemy icon indicating copy to clipboard operation
snowflake-sqlalchemy copied to clipboard

Published 20 hours ago • verified publisher icon snowflakedb

SNOW-716692: A literal with an array generates incorrect results

Open sfc-gh-kbregula opened this issue 2 years ago • 2 comments

Please answer these questions before submitting your issue. Thanks!

  1. What version of Python are you using?
Python 3.10.4 (main, Dec 12 2022, 10:31:01) [Clang 12.0.0 (clang-1200.0.32.29)]
  1. What operating system and processor architecture are you using?
macOS-13.0.1-x86_64-i386-64bit
  1. What are the component versions in the environment (pip freeze)?
$python -m pip freeze | grep snowflake
snowflake-connector-python==2.8.3
snowflake-sqlalchemy==1.4.4
  1. What did you do?

I wanted to use sa.literal, which contains sa.ARRAY, but the SQL query executed is invalid, but it is correctly generated by SQLAlchemy.

For following code:

from sqlalchemy import create_engine
engine = create_engine(
    ....,
    echo=True,
)
connection = engine.connect()
import sqlalchemy as sa
from sqlalchemy.sql import select, literal

result = connection.execute(
    select(
        literal((1, 2, 3), type_=sa.ARRAY(item_type=sa.SmallInteger)).label("tmp")
    )
)
print("Query: ", result.cursor.query)
result_data = result.fetchall()
print(result_data)
from tabulate import tabulate
tab = tabulate(list(map(list, result_data)))
print(tab)

I have the following output:

2022-12-15 15:33:44,893 INFO sqlalchemy.engine.Engine select current_database(), current_schema();
2022-12-15 15:33:44,894 INFO sqlalchemy.engine.Engine [raw sql] {}
2022-12-15 15:33:45,082 INFO sqlalchemy.engine.Engine SELECT %(param_1)s AS tmp
2022-12-15 15:33:45,083 INFO sqlalchemy.engine.Engine [dialect snowflake+snowflake does not support caching 0.00019s] {'param_1': (1, 2, 3)}
Query:  SELECT 1,2,3 AS tmp
[(1, 2, 3)]
-  -  -
1  2  3
-  -  -

As workaround, I use the following code:

result = connection.execute(
    select(
        sa.func.array_construct(*(1, 2, 3), type_=sa.ARRAY(item_type=sa.SmallInteger)).label("tmp")
    )
)
  1. What did you expect to see?

Instead of 1 column, the result contains 3 columns.

  1. Can you set logging to DEBUG and collect the logs?
Ful llogs 
2022-12-15 15:37:28,049 - MainThread connection.py:275 - __init__() - INFO - Snowflake Connector for Python Version: 2.8.3, Python Version: 3.10.4, Platform: macOS-13.0.1-x86_64-i386-64bit
2022-12-15 15:37:28,049 - MainThread connection.py:520 - connect() - DEBUG - connect
2022-12-15 15:37:28,049 - MainThread connection.py:810 - __config() - DEBUG - __config
2022-12-15 15:37:28,049 - MainThread connection.py:934 - __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.
2022-12-15 15:37:28,049 - MainThread connection.py:952 - __config() - INFO - Setting use_openssl_only mode to False
2022-12-15 15:37:28,050 - MainThread converter.py:145 - __init__() - DEBUG - use_numpy: False
2022-12-15 15:37:28,050 - MainThread connection.py:713 - __open_connection() - DEBUG - REST API object was created: gs25896.eu-central-1.snowflakecomputing.com:443
2022-12-15 15:37:28,050 - MainThread auth.py:170 - authenticate() - DEBUG - authenticate
2022-12-15 15:37:28,050 - MainThread auth.py:200 - authenticate() - DEBUG - assertion content: *********
2022-12-15 15:37:28,050 - MainThread auth.py:203 - authenticate() - DEBUG - account=gs25896, user=IBIS_TESTING, database=IBIS_TESTING42, schema=IBIS_TESTING42, warehouse=COMPUTE_WH, role=ACCOUNTADMIN, request_id=dba0ea68-4c29-4649-83c9-1d040906d093
2022-12-15 15:37:28,050 - MainThread auth.py:236 - authenticate() - DEBUG - body['data']: {'CLIENT_APP_ID': 'PythonConnector', 'CLIENT_APP_VERSION': '2.8.3', 'SVN_REVISION': None, 'ACCOUNT_NAME': 'gs25896', 'LOGIN_NAME': 'IBIS_TESTING', 'CLIENT_ENVIRONMENT': {'APPLICATION': 'PythonConnector', 'OS': 'Darwin', 'OS_VERSION': 'macOS-13.0.1-x86_64-i386-64bit', 'PYTHON_VERSION': '3.10.4', 'PYTHON_RUNTIME': 'CPython', 'PYTHON_COMPILER': 'Clang 12.0.0 (clang-1200.0.32.29)', 'OCSP_MODE': 'FAIL_OPEN', 'TRACING': 10, 'LOGIN_TIMEOUT': 120, 'NETWORK_TIMEOUT': None}, 'SESSION_PARAMETERS': {'AUTOCOMMIT': False, 'CLIENT_PREFETCH_THREADS': 4}}
2022-12-15 15:37:28,050 - MainThread auth.py:254 - authenticate() - DEBUG - Timeout set to 120
2022-12-15 15:37:28,050 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2022-12-15 15:37:28,050 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2022-12-15 15:37:28,050 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:28,051 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: 120, retry cnt: 1
2022-12-15 15:37:28,051 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: b911ecd0-1266-4315-bed4-b3deb45538f9
2022-12-15 15:37:28,051 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:28,059 - MainThread connectionpool.py:1003 - _new_conn() - DEBUG - Starting new HTTPS connection (1): gs25896.eu-central-1.snowflakecomputing.com:443
2022-12-15 15:37:28,377 - MainThread ocsp_snowflake.py:485 - reset_cache_dir() - DEBUG - cache directory: /Users/kbregula/Library/Caches/Snowflake
2022-12-15 15:37:28,558 - MainThread ssl_wrap_socket.py:80 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None
2022-12-15 15:37:28,558 - MainThread ocsp_snowflake.py:523 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file:///Users/kbregula/Library/Caches/Snowflake/ocsp_response_cache.json
2022-12-15 15:37:28,558 - MainThread ocsp_snowflake.py:526 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 197
2022-12-15 15:37:28,558 - 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
2022-12-15 15:37:28,558 - MainThread ocsp_snowflake.py:346 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None
2022-12-15 15:37:28,558 - MainThread ocsp_snowflake.py:956 - validate() - DEBUG - validating certificate: gs25896.eu-central-1.snowflakecomputing.com
2022-12-15 15:37:28,559 - MainThread ocsp_asn1crypto.py:427 - extract_certificate_chain() - DEBUG - # of certificates: 4
2022-12-15 15:37:28,559 - MainThread ocsp_asn1crypto.py:432 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('common_name', '*.eu-central-1.snowflakecomputing.com')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('organizational_unit_name', 'Server CA 1B'), ('common_name', 'Amazon')])
2022-12-15 15:37:28,560 - MainThread ocsp_asn1crypto.py:432 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('organizational_unit_name', 'Server CA 1B'), ('common_name', 'Amazon')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon Root CA 1')])
2022-12-15 15:37:28,565 - MainThread ocsp_asn1crypto.py:432 - 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')])
2022-12-15 15:37:28,565 - MainThread ocsp_asn1crypto.py:432 - 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')])
2022-12-15 15:37:28,572 - MainThread ocsp_asn1crypto.py:112 - read_cert_bundle() - DEBUG - reading certificate bundle: /Users/kbregula/Library/Caches/pypoetry/virtualenvs/ibis-framework-ENEkyyjJ-py3.10/lib/python3.10/site-packages/certifi/cacert.pem
2022-12-15 15:37:28,606 - MainThread ocsp_asn1crypto.py:453 - 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')])
2022-12-15 15:37:28,608 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('common_name', '*.eu-central-1.snowflakecomputing.com')])
2022-12-15 15:37:28,610 - MainThread ocsp_asn1crypto.py:227 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-09-15 19:41:06+00:00
2022-12-15 15:37:28,610 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('organizational_unit_name', 'Server CA 1B'), ('common_name', 'Amazon')])
2022-12-15 15:37:28,612 - MainThread ocsp_asn1crypto.py:227 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-09-15 19:45:34+00:00
2022-12-15 15:37:28,612 - 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')])
2022-12-15 15:37:28,619 - MainThread ocsp_asn1crypto.py:227 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2023-06-22 07:00:00+00:00
2022-12-15 15:37:28,619 - 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')])
2022-12-15 15:37:28,622 - MainThread ocsp_snowflake.py:1013 - _validate() - DEBUG - ok
2022-12-15 15:37:28,926 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /session/v1/login-request?request_id=dba0ea68-4c29-4649-83c9-1d040906d093&databaseName=IBIS_TESTING42&schemaName=IBIS_TESTING42&warehouse=COMPUTE_WH&roleName=ACCOUNTADMIN&request_guid=b911ecd0-1266-4315-bed4-b3deb45538f9 HTTP/1.1" 200 1508
2022-12-15 15:37:28,927 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:28,927 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:28,928 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:28,928 - MainThread auth.py:373 - authenticate() - DEBUG - completed authentication
2022-12-15 15:37:28,928 - MainThread auth.py:416 - authenticate() - DEBUG - token = ******
2022-12-15 15:37:28,928 - MainThread auth.py:419 - authenticate() - DEBUG - master_token = ******
2022-12-15 15:37:28,928 - MainThread auth.py:423 - authenticate() - DEBUG - id_token = NULL
2022-12-15 15:37:28,928 - MainThread auth.py:427 - authenticate() - DEBUG - mfa_token = NULL
2022-12-15 15:37:28,929 - MainThread connection.py:632 - cursor() - DEBUG - cursor
2022-12-15 15:37:28,930 INFO sqlalchemy.engine.Engine select current_database(), current_schema();
2022-12-15 15:37:28,930 INFO sqlalchemy.engine.Engine [raw sql] {}
2022-12-15 15:37:28,930 - MainThread cursor.py:622 - execute() - DEBUG - executing SQL/command
2022-12-15 15:37:28,930 - MainThread connection.py:1264 - _process_params_dict() - DEBUG - parameters: {}
2022-12-15 15:37:28,930 - MainThread cursor.py:661 - execute() - DEBUG - binding: [select current_database(), current_schema();] with input=[{}], processed=[{}]
2022-12-15 15:37:28,930 - MainThread cursor.py:707 - execute() - INFO - query: [select current_database(), current_schema();]
2022-12-15 15:37:28,930 - MainThread connection.py:1310 - _next_sequence_counter() - DEBUG - sequence counter: 1
2022-12-15 15:37:28,930 - MainThread cursor.py:454 - _execute_helper() - DEBUG - Request id: 018d3154-4fd3-4825-8bc3-e94fb963ac4e
2022-12-15 15:37:28,930 - MainThread cursor.py:456 - _execute_helper() - DEBUG - running query [select current_database(), current_schema();]
2022-12-15 15:37:28,930 - MainThread cursor.py:463 - _execute_helper() - DEBUG - is_file_transfer: True
2022-12-15 15:37:28,931 - MainThread connection.py:980 - cmd_query() - DEBUG - _cmd_query
2022-12-15 15:37:28,931 - MainThread connection.py:1003 - cmd_query() - DEBUG - sql=[select current_database(), current_schema();], sequence_id=[1], is_file_transfer=[False]
2022-12-15 15:37:28,931 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:28,931 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2022-12-15 15:37:28,931 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: e371cc55-fe5c-4d22-b4af-673634ac295f
2022-12-15 15:37:28,931 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,024 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=018d3154-4fd3-4825-8bc3-e94fb963ac4e&request_guid=e371cc55-fe5c-4d22-b4af-673634ac295f HTTP/1.1" 200 1604
2022-12-15 15:37:29,025 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,025 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,025 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,025 - MainThread network.py:739 - _post_request() - DEBUG - Query id: 01a8fc8d-3201-774b-0001-a856000900aa
2022-12-15 15:37:29,026 - MainThread cursor.py:729 - execute() - DEBUG - sfqid: 01a8fc8d-3201-774b-0001-a856000900aa
2022-12-15 15:37:29,026 - MainThread cursor.py:731 - execute() - INFO - query execution done
2022-12-15 15:37:29,026 - MainThread cursor.py:733 - execute() - DEBUG - SUCCESS
2022-12-15 15:37:29,026 - MainThread cursor.py:736 - execute() - DEBUG - PUT OR GET: False
2022-12-15 15:37:29,026 - MainThread cursor.py:833 - _init_result_and_meta() - DEBUG - Query result format: arrow
2022-12-15 15:37:29,026 - MainThread cursor.py:847 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2022-12-15 15:37:29,030 - MainThread arrow_iterator.cpython-310-darwin.so:0 - __cinit__() - DEBUG - Batches read: 1
2022-12-15 15:37:29,030 - MainThread CArrowIterator.cpp:16 - CArrowIterator() - DEBUG - Arrow BatchSize: 1
2022-12-15 15:37:29,030 - MainThread CArrowChunkIterator.cpp:50 - CArrowChunkIterator() - DEBUG - Arrow chunk info: batchCount 1, columnCount 2, use_numpy: 0
2022-12-15 15:37:29,030 - MainThread result_set.py:58 - result_set_iterator() - DEBUG - beginning to schedule result batch downloads
2022-12-15 15:37:29,031 - MainThread CArrowChunkIterator.cpp:74 - next() - DEBUG - Current batch index: 0, rows in current batch: 1
2022-12-15 15:37:29,031 - MainThread connection.py:632 - cursor() - DEBUG - cursor
2022-12-15 15:37:29,031 - MainThread cursor.py:622 - execute() - DEBUG - executing SQL/command
2022-12-15 15:37:29,031 - MainThread cursor.py:661 - execute() - DEBUG - binding: [ROLLBACK] with input=[None], processed=[{}]
2022-12-15 15:37:29,031 - MainThread cursor.py:707 - execute() - INFO - query: [ROLLBACK]
2022-12-15 15:37:29,031 - MainThread connection.py:1310 - _next_sequence_counter() - DEBUG - sequence counter: 2
2022-12-15 15:37:29,031 - MainThread cursor.py:454 - _execute_helper() - DEBUG - Request id: 541e4038-5a5a-4a58-b9ce-d43363090307
2022-12-15 15:37:29,031 - MainThread cursor.py:456 - _execute_helper() - DEBUG - running query [ROLLBACK]
2022-12-15 15:37:29,031 - MainThread cursor.py:463 - _execute_helper() - DEBUG - is_file_transfer: True
2022-12-15 15:37:29,031 - MainThread connection.py:980 - cmd_query() - DEBUG - _cmd_query
2022-12-15 15:37:29,031 - MainThread connection.py:1003 - cmd_query() - DEBUG - sql=[ROLLBACK], sequence_id=[2], is_file_transfer=[False]
2022-12-15 15:37:29,032 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:29,032 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2022-12-15 15:37:29,032 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: 7e308e58-0d53-4364-b428-e373020230ba
2022-12-15 15:37:29,032 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,124 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=541e4038-5a5a-4a58-b9ce-d43363090307&request_guid=7e308e58-0d53-4364-b428-e373020230ba HTTP/1.1" 200 1101
2022-12-15 15:37:29,125 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,125 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,125 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,125 - MainThread network.py:739 - _post_request() - DEBUG - Query id: 01a8fc8d-3201-77bc-0001-a8560008ff76
2022-12-15 15:37:29,125 - MainThread cursor.py:729 - execute() - DEBUG - sfqid: 01a8fc8d-3201-77bc-0001-a8560008ff76
2022-12-15 15:37:29,125 - MainThread cursor.py:731 - execute() - INFO - query execution done
2022-12-15 15:37:29,125 - MainThread cursor.py:733 - execute() - DEBUG - SUCCESS
2022-12-15 15:37:29,125 - MainThread cursor.py:736 - execute() - DEBUG - PUT OR GET: False
2022-12-15 15:37:29,126 - MainThread cursor.py:833 - _init_result_and_meta() - DEBUG - Query result format: json
2022-12-15 15:37:29,126 - MainThread result_batch.py:440 - _parse() - DEBUG - parsing for result batch id: 1
2022-12-15 15:37:29,126 - MainThread cursor.py:847 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2022-12-15 15:37:29,127 - MainThread connection.py:632 - cursor() - DEBUG - cursor
2022-12-15 15:37:29,127 INFO sqlalchemy.engine.Engine SELECT %(param_1)s AS tmp
2022-12-15 15:37:29,127 INFO sqlalchemy.engine.Engine [dialect snowflake+snowflake does not support caching 0.00031s] {'param_1': (1, 2, 3)}
2022-12-15 15:37:29,127 - MainThread cursor.py:622 - execute() - DEBUG - executing SQL/command
2022-12-15 15:37:29,133 - MainThread connection.py:1264 - _process_params_dict() - DEBUG - parameters: {'param_1': '1,2,3'}
2022-12-15 15:37:29,133 - MainThread cursor.py:661 - execute() - DEBUG - binding: [SELECT %(param_1)s AS tmp] with input=[{'param_1': (1, 2, 3)}], processed=[{'param_1': '1,2,3'}]
2022-12-15 15:37:29,133 - MainThread cursor.py:707 - execute() - INFO - query: [SELECT 1,2,3 AS tmp]
2022-12-15 15:37:29,134 - MainThread connection.py:1310 - _next_sequence_counter() - DEBUG - sequence counter: 3
2022-12-15 15:37:29,134 - MainThread cursor.py:454 - _execute_helper() - DEBUG - Request id: f303b558-3b47-42ca-954e-d1c2a60ca041
2022-12-15 15:37:29,134 - MainThread cursor.py:456 - _execute_helper() - DEBUG - running query [SELECT 1,2,3 AS tmp]
2022-12-15 15:37:29,134 - MainThread cursor.py:463 - _execute_helper() - DEBUG - is_file_transfer: True
2022-12-15 15:37:29,134 - MainThread connection.py:980 - cmd_query() - DEBUG - _cmd_query
2022-12-15 15:37:29,134 - MainThread connection.py:1003 - cmd_query() - DEBUG - sql=[SELECT 1,2,3 AS tmp], sequence_id=[3], is_file_transfer=[False]
2022-12-15 15:37:29,134 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:29,134 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2022-12-15 15:37:29,134 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: a1215f57-6312-483c-8556-8407ab26a8be
2022-12-15 15:37:29,134 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,213 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=f303b558-3b47-42ca-954e-d1c2a60ca041&request_guid=a1215f57-6312-483c-8556-8407ab26a8be HTTP/1.1" 200 1589
2022-12-15 15:37:29,214 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,214 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,214 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,214 - MainThread network.py:739 - _post_request() - DEBUG - Query id: 01a8fc8d-3201-77bc-0001-a8560008ff7a
2022-12-15 15:37:29,214 - MainThread cursor.py:729 - execute() - DEBUG - sfqid: 01a8fc8d-3201-77bc-0001-a8560008ff7a
2022-12-15 15:37:29,214 - MainThread cursor.py:731 - execute() - INFO - query execution done
2022-12-15 15:37:29,214 - MainThread cursor.py:733 - execute() - DEBUG - SUCCESS
2022-12-15 15:37:29,214 - MainThread cursor.py:736 - execute() - DEBUG - PUT OR GET: False
2022-12-15 15:37:29,214 - MainThread cursor.py:833 - _init_result_and_meta() - DEBUG - Query result format: arrow
2022-12-15 15:37:29,214 - MainThread cursor.py:847 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
Query:  SELECT 1,2,3 AS tmp
2022-12-15 15:37:29,215 - MainThread arrow_iterator.cpython-310-darwin.so:0 - __cinit__() - DEBUG - Batches read: 1
2022-12-15 15:37:29,215 - MainThread CArrowIterator.cpp:16 - CArrowIterator() - DEBUG - Arrow BatchSize: 1
2022-12-15 15:37:29,215 - MainThread CArrowChunkIterator.cpp:50 - CArrowChunkIterator() - DEBUG - Arrow chunk info: batchCount 1, columnCount 3, use_numpy: 0
2022-12-15 15:37:29,215 - MainThread result_set.py:58 - result_set_iterator() - DEBUG - beginning to schedule result batch downloads
2022-12-15 15:37:29,215 - MainThread CArrowChunkIterator.cpp:74 - next() - DEBUG - Current batch index: 0, rows in current batch: 1
[(1, 2, 3)]
-  -  -
1  2  3
-  -  -
2022-12-15 15:37:29,239 - MainThread connection.py:632 - cursor() - DEBUG - cursor
2022-12-15 15:37:29,239 - MainThread cursor.py:622 - execute() - DEBUG - executing SQL/command
2022-12-15 15:37:29,239 - MainThread cursor.py:661 - execute() - DEBUG - binding: [ROLLBACK] with input=[None], processed=[{}]
2022-12-15 15:37:29,239 - MainThread cursor.py:707 - execute() - INFO - query: [ROLLBACK]
2022-12-15 15:37:29,239 - MainThread connection.py:1310 - _next_sequence_counter() - DEBUG - sequence counter: 4
2022-12-15 15:37:29,239 - MainThread cursor.py:454 - _execute_helper() - DEBUG - Request id: 6c671996-d48f-43cd-ac2b-9ac6937c7d5d
2022-12-15 15:37:29,239 - MainThread cursor.py:456 - _execute_helper() - DEBUG - running query [ROLLBACK]
2022-12-15 15:37:29,239 - MainThread cursor.py:463 - _execute_helper() - DEBUG - is_file_transfer: True
2022-12-15 15:37:29,239 - MainThread connection.py:980 - cmd_query() - DEBUG - _cmd_query
2022-12-15 15:37:29,239 - MainThread connection.py:1003 - cmd_query() - DEBUG - sql=[ROLLBACK], sequence_id=[4], is_file_transfer=[False]
2022-12-15 15:37:29,239 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:29,239 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2022-12-15 15:37:29,240 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: 689c9a8a-2f43-489f-bd29-d44099e6a8c6
2022-12-15 15:37:29,240 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,327 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=6c671996-d48f-43cd-ac2b-9ac6937c7d5d&request_guid=689c9a8a-2f43-489f-bd29-d44099e6a8c6 HTTP/1.1" 200 1102
2022-12-15 15:37:29,328 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,328 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,328 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,328 - MainThread network.py:739 - _post_request() - DEBUG - Query id: 01a8fc8d-3201-774b-0001-a856000900ae
2022-12-15 15:37:29,328 - MainThread cursor.py:729 - execute() - DEBUG - sfqid: 01a8fc8d-3201-774b-0001-a856000900ae
2022-12-15 15:37:29,328 - MainThread cursor.py:731 - execute() - INFO - query execution done
2022-12-15 15:37:29,328 - MainThread cursor.py:733 - execute() - DEBUG - SUCCESS
2022-12-15 15:37:29,329 - MainThread cursor.py:736 - execute() - DEBUG - PUT OR GET: False
2022-12-15 15:37:29,329 - MainThread cursor.py:833 - _init_result_and_meta() - DEBUG - Query result format: json
2022-12-15 15:37:29,329 - MainThread result_batch.py:440 - _parse() - DEBUG - parsing for result batch id: 1
2022-12-15 15:37:29,329 - MainThread cursor.py:847 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2022-12-15 15:37:29,329 - MainThread connection.py:565 - close() - INFO - closed
2022-12-15 15:37:29,329 - MainThread telemetry.py:209 - close() - DEBUG - Closing telemetry client.
2022-12-15 15:37:29,330 - MainThread telemetry.py:174 - send_batch() - DEBUG - Sending 1 logs to telemetry. Data is {'logs': [{'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_imported_packages', 'value': "{'sys', 'sysconfig', 'threading', 'textwrap', 'tarfile', 'snowflake', 'html', 'oscrypto', 'difflib', 'idna', 'socket', 'charset_normalizer', 'io', 'concurrent', 'encodings', 'sre_parse', 'quopri', 'time', 'operator', 'struct', 'cmath', 'uu', 'enum', 'traceback', 'types', 'json', 'stat', 'string', 'collections', 'sre_constants', 'bisect', 'dis', 'cryptography', 'posix', 'fractions', 'email', 'linecache', 'typing', 'abc', 'pandas', 'math', 'base64', 'xml', 'sqlalchemy', 'urllib', 'random', 'calendar', 'importlib', 'queue', 'mmap', 'heapq', 'unicodedata', 'decimal', 'shlex', 'tokenize', 'requests', 'opcode', 'genericpath', 'gc', 'ssl', 'pickle', 'webbrowser', 'asyncio', 'zoneinfo', 'six', 'jwt', 'OpenSSL', 'contextvars', 'filelock', 'functools', 'hmac', 'datetime', 'bz2', 'dataclasses', 'sre_compile', 'numpy', 'reprlib', 'zipfile', 'hashlib', 'pyexpat', 'pycparser', 'pydoc', 'zipimport', 'uuid', 'gzip', 'ipaddress', 'http', 'pytz', 'shutil', 're', 'ctypes', 'typing_extensions', 'weakref', 'asn1crypto', 'secrets', 'glob', 'csv', 'pyarrow', 'os', 'site', 'contextlib', 'ast', 'ntpath', 'fcntl', 'marshal', 'binascii', 'warnings', 'itertools', 'pwd', 'zlib', 'grp', 'locale', 'configparser', 'copy', 'tempfile', 'select', 'plistlib', 'inspect', 'subprocess', 'stringprep', 'signal', 'dateutil', 'pathlib', 'Cryptodome', 'errno', 'lzma', 'pprint', 'fnmatch', 'mimetypes', 'posixpath', 'array', 'greenlet', 'certifi', 'platform', 'urllib3', 'pkg_resources', 'numbers', 'atexit', 'logging', 'copyreg', 'pkgutil', 'selectors', 'builtins', 'token', 'cython_runtime', 'codecs', 'cffi', 'keyword'}"}, 'timestamp': '1671115048929'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_pyformat_empty_seq_interpolation', 'query_id': None, 'value': 0}, 'timestamp': '1671115048930'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_time_consume_first_result', 'query_id': '01a8fc8d-3201-774b-0001-a856000900aa', 'value': -26}, 'timestamp': '1671115049026'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_time_consume_first_result', 'query_id': '01a8fc8d-3201-77bc-0001-a8560008ff76', 'value': -26}, 'timestamp': '1671115049125'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_time_consume_first_result', 'query_id': '01a8fc8d-3201-77bc-0001-a8560008ff7a', 'value': -27}, 'timestamp': '1671115049214'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_time_consume_last_result', 'query_id': '01a8fc8d-3201-77bc-0001-a8560008ff7a', 'value': 1}, 'timestamp': '1671115049215'}, {'message': {'driver_type': 'PythonConnector', 'driver_version': '2.8.3', 'source': 'PythonConnector', 'type': 'client_time_consume_first_result', 'query_id': '01a8fc8d-3201-774b-0001-a856000900ae', 'value': -24}, 'timestamp': '1671115049328'}]}.
2022-12-15 15:37:29,331 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:29,331 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: 5, retry cnt: 1
2022-12-15 15:37:29,331 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: 23bae054-ec12-4415-b26e-fe69ea326a72
2022-12-15 15:37:29,331 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,371 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /telemetry/send?request_guid=23bae054-ec12-4415-b26e-fe69ea326a72 HTTP/1.1" 200 86
2022-12-15 15:37:29,371 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,371 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,371 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,371 - MainThread telemetry.py:198 - send_batch() - DEBUG - Successfully uploading metrics to telemetry.
2022-12-15 15:37:29,371 - MainThread connection.py:568 - close() - INFO - No async queries seem to be running, deleting session
2022-12-15 15:37:29,372 - MainThread network.py:1147 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 1/1 active sessions
2022-12-15 15:37:29,372 - MainThread network.py:827 - _request_exec_wrapper() - DEBUG - remaining request timeout: 5, retry cnt: 1
2022-12-15 15:37:29,372 - MainThread network.py:808 - add_request_guid() - DEBUG - Request guid: 88818d30-bc23-4764-862e-36cc41de1f38
2022-12-15 15:37:29,372 - MainThread network.py:1006 - _request_exec() - DEBUG - socket timeout: 60
2022-12-15 15:37:29,450 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://gs25896.eu-central-1.snowflakecomputing.com:443 "POST /session?delete=true&request_guid=88818d30-bc23-4764-862e-36cc41de1f38 HTTP/1.1" 200 76
2022-12-15 15:37:29,450 - MainThread network.py:1032 - _request_exec() - DEBUG - SUCCESS
2022-12-15 15:37:29,451 - MainThread network.py:1152 - _use_requests_session() - DEBUG - Session status for SessionPool 'gs25896.eu-central-1.snowflakecomputing.com', SessionPool 0/1 active sessions
2022-12-15 15:37:29,451 - MainThread network.py:715 - _post_request() - DEBUG - ret[code] = None, after post request
2022-12-15 15:37:29,452 - MainThread connection.py:579 - close() - DEBUG - Session is closed
2022-12-15 15:37:29,488 - MainThread connection.py:556 - close() - DEBUG - Rest object has been destroyed, cannot close session

sfc-gh-kbregula avatar Dec 17 '22 01:12 sfc-gh-kbregula

Glad to hear that there is a workaround :)

Unfortunately I don't think python connector supports binding an array data in pyformat, and the tuple is interpreted as multiple values joined by a comma instead of an array. Supporting it in python connector might be a big behavior change, so I wonder if we should do it in sqlalchemy layer. @sfc-gh-aling @sfc-gh-mkeller : what do you think?

sfc-gh-sfan avatar Dec 19 '22 18:12 sfc-gh-sfan

looks like there is no priority on this one, so marking it as closed for now to clean up old tickets. If it's still an issue, we can deal with it internally.

sfc-gh-dszmolka avatar Mar 15 '24 12:03 sfc-gh-dszmolka