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-940628: executemany fails using subquery with multiple rows in bind list - throws error: "Bind variable ? not set" #1770

Closed
georgeb-accelins opened this issue Oct 13, 2023 · 1 comment

Comments

@georgeb-accelins
Copy link

Python version

Python 3.11.0 (main, Oct 24 2022, 18:26:48) [MSC v.1933 64 bit (AMD64)]

Operating system and processor architecture

Windows-10-10.0.22621-SP0

Installed packages

asn1crypto==1.5.1
certifi==2023.7.22
cffi==1.16.0
charset-normalizer==3.3.0
cryptography==41.0.4
filelock==3.12.4
idna==3.4
oscrypto==1.3.0
packaging==23.2
platformdirs==3.11.0
pycparser==2.21
pycryptodomex==3.19.0
PyJWT==2.8.0
pyOpenSSL==23.2.0
pytz==2023.3.post1
requests==2.31.0
snowflake-connector-python==3.3.0
sortedcontainers==2.4.0
tomlkit==0.12.1
typing_extensions==4.8.0
urllib3==1.26.17

What did you do?

import snowflake.connector
import logging
import os


if __name__ == "__main__":
    for logger_name in ('snowflake.connector',):
        logger = logging.getLogger(logger_name)
        logger.setLevel(logging.DEBUG)
        ch = logging.StreamHandler()
        ch.setLevel(logging.DEBUG)
        ch.setFormatter(logging.Formatter('%(asctime)s - %(threadName)s %(filename)s:%(lineno)d - %(funcName)s() - %(levelname)s - %(message)s'))
        logger.addHandler(ch)

    snowflake_conn = snowflake.connector.connect(
        user=os.environ.get("SNOWFLAKE_USER"),
        account=os.environ.get("SNOWFLAKE_ACCOUNT"),
        password=os.environ.get("SNOWFLAKE_PASSWORD"),
        database="BUG_TEST",
        schema="BUG_TEST",
        autocommit=False,
        paramstyle="qmark",
    )

    database_name = "bug_test"
    schema_name = "bug_test"
    table_name = f"{database_name}.{schema_name}.bug_test_json"

    # Create database, schema and table
    snowflake_cursor = snowflake_conn.cursor()
    snowflake_cursor.execute(f"create database if not exists {database_name}")
    snowflake_cursor.execute(f"create schema if not exists {database_name}.{schema_name}")
    snowflake_cursor.execute(f"create or replace table {table_name}(f1 number, f2 variant)")

    some_json = '{ "name": "bug", "value": 1 }'

    # Succeeds if only one row in list
    data_to_insert = [(1, some_json)]
    snowflake_cursor = snowflake_conn.cursor()
    snowflake_cursor.executemany(f"insert into {table_name}(f1, f2) select ?, parse_json(?)", data_to_insert)
    snowflake_conn.commit()

    # Fails if more than one row in list
    data_to_insert = [(2, some_json), (3, some_json)]
    snowflake_cursor = snowflake_conn.cursor()
    snowflake_cursor.executemany(f"insert into {table_name}(f1, f2) select ?, parse_json(?)", data_to_insert)
    snowflake_conn.commit()

What did you expect to see?

Multiple records should be inserted

Can you set logging to DEBUG and collect the logs?

2023-10-13 11:25:39,472 - MainThread connection.py:282 - __init__() - INFO - Snowflake Connector for Python Version: 3.0.3, Python Version: 3.10.11, Platform: Windows-10-10.0.22621-SP0
2023-10-13 11:25:39,474 - MainThread connection.py:541 - connect() - DEBUG - connect
2023-10-13 11:25:39,474 - MainThread connection.py:852 - __config() - DEBUG - __config
2023-10-13 11:25:39,474 - 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-10-13 11:25:39,474 - MainThread connection.py:1007 - __config() - INFO - Setting use_openssl_only mode to False
2023-10-13 11:25:39,476 - MainThread converter.py:150 - __init__() - DEBUG - use_numpy: False
2023-10-13 11:25:39,476 - MainThread converter_issue23517.py:27 - __init__() - DEBUG - initialized
2023-10-13 11:25:39,477 - MainThread connection.py:734 - __open_connection() - DEBUG - REST API object was created: ********.snowflakecomputing.com:443
2023-10-13 11:25:39,477 - MainThread _auth.py:171 - authenticate() - DEBUG - authenticate
2023-10-13 11:25:39,479 - MainThread _auth.py:201 - authenticate() - DEBUG - assertion content: *********
2023-10-13 11:25:39,479 - MainThread _auth.py:204 - authenticate() - DEBUG - account=********, user=********, database=BUG_TEST, schema=BUG_TEST, warehouse=None, role=None, request_id=4fa6f7da-6f73-413e-a2e7-663cbb5a81b9
2023-10-13 11:25:39,480 - MainThread _auth.py:237 - authenticate() - DEBUG - body['data']: {'CLIENT_APP_ID': 'PythonConnector', 'CLIENT_APP_VERSION': '3.0.3', 'SVN_REVISION': None, 'ACCOUNT_NAME': '********', 'LOGIN_NAME': '********', 'CLIENT_ENVIRONMENT': {'APPLICATION': 'PythonConnector', 'OS': 'Windows', 'OS_VERSION': 'Windows-10-10.0.22621-SP0', 'PYTHON_VERSION': '3.10.11', 'PYTHON_RUNTIME': 'CPython', 'PYTHON_COMPILER': 'MSC v.1929 64 bit (AMD64)', 'OCSP_MODE': 'FAIL_OPEN', 'TRACING': 10, 'LOGIN_TIMEOUT': 120, 'NETWORK_TIMEOUT': None}, 'SESSION_PARAMETERS': {'AUTOCOMMIT': False, 'CLIENT_PREFETCH_THREADS': 4}}
2023-10-13 11:25:39,480 - MainThread _auth.py:247 - authenticate() - DEBUG - Timeout set to 120
2023-10-13 11:25:39,482 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2023-10-13 11:25:39,483 - MainThread retry.py:351 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None)
2023-10-13 11:25:39,483 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:25:39,483 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: 120, retry cnt: 1
2023-10-13 11:25:39,484 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: d025c99d-ef48-4f21-93d6-2c53f79301d3
2023-10-13 11:25:39,484 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:25:39,492 - MainThread connectionpool.py:1003 - _new_conn() - DEBUG - Starting new HTTPS connection (1): ********.snowflakecomputing.com:443
2023-10-13 11:25:41,470 - MainThread cache.py:545 - _save() - DEBUG - acquiring C:\Users\Bo********\AppData\Local\Snowflake\Caches\ocsp_response_validation_cache.lock timed out, skipping saving...
2023-10-13 11:25:41,470 - MainThread ocsp_snowflake.py:485 - reset_cache_dir() - DEBUG - cache directory: C:\Users\Bo********\AppData\Local\Snowflake\Caches
2023-10-13 11:25:41,859 - MainThread ssl_wrap_socket.py:81 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None
2023-10-13 11:25:41,859 - MainThread ocsp_snowflake.py:523 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file://C:/Users/Bo********/AppData/Local/Snowflake/Caches/ocsp_response_cache.json  
2023-10-13 11:25:41,861 - MainThread ocsp_snowflake.py:526 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 200
2023-10-13 11:25:41,861 - 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-10-13 11:25:41,862 - MainThread ocsp_snowflake.py:346 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None
2023-10-13 11:25:41,862 - MainThread ocsp_snowflake.py:956 - validate() - DEBUG - validating certificate: ********.snowflakecomputing.com
2023-10-13 11:25:41,863 - MainThread ocsp_asn1crypto.py:435 - extract_certificate_chain() - DEBUG - # of certificates: 4
2023-10-13 11:25:41,865 - 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-10-13 11:25:41,866 - 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-10-13 11:25:41,868 - 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-10-13 11:25:41,870 - 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-10-13 11:25:41,876 - MainThread ocsp_asn1crypto.py:114 - read_cert_bundle() - DEBUG - reading certificate bundle: C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\certifi\cacert.pem
2023-10-13 11:25:41,901 - 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-10-13 11:25:41,905 - MainThread ocsp_snowflake.py:722 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('common_name', '*.eu-west-1.snowflakecomputing.com')])
2023-10-13 11:25:41,913 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-08-23 22:57:03+00:00
2023-10-13 11:25:41,917 - 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-10-13 11:25:41,926 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-08-23 22:59:53+00:00
2023-10-13 11:25:41,928 - 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-10-13 11:25:41,933 - 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-10-13 11:25:41,934 - 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-10-13 11:25:41,940 - MainThread ocsp_snowflake.py:1013 - _validate() - DEBUG - ok
2023-10-13 11:25:42,300 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /session/v1/login-request?request_id=4fa6f7da-6f73-413e-a2e7-663cbb5a81b9&databaseName=BUG_TEST&schemaName=BUG_TEST&request_guid=d025c99d-ef48-4f21-93d6-2c53f79301d3 HTTP/1.1" 200 1542
2023-10-13 11:25:42,304 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:25:42,306 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:25:42,306 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:25:42,307 - MainThread _auth.py:366 - authenticate() - DEBUG - completed authentication
2023-10-13 11:25:42,308 - MainThread _auth.py:413 - authenticate() - DEBUG - token = ******
2023-10-13 11:25:42,308 - MainThread _auth.py:416 - authenticate() - DEBUG - master_token = ******
2023-10-13 11:25:42,309 - MainThread _auth.py:420 - authenticate() - DEBUG - id_token = NULL
2023-10-13 11:25:42,310 - MainThread _auth.py:424 - authenticate() - DEBUG - mfa_token = NULL
2023-10-13 11:25:46,140 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-10-13 11:25:47,310 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:25:47,311 - MainThread cursor.py:800 - execute() - INFO - query: [create database if not exists bug_test]
2023-10-13 11:25:47,312 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 1
2023-10-13 11:25:47,312 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: c0d61301-59f8-4209-8988-3f0d68747b3a
2023-10-13 11:25:47,312 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [create database if not exists bug_test]
2023-10-13 11:25:47,313 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:25:47,314 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:25:47,314 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[create database if not exists bug_test], sequence_id=[1], is_file_transfer=[False]
2023-10-13 11:25:47,315 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:25:47,316 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:25:47,316 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: e53a2e24-74a8-4b51-87ac-e720d1d90f02
2023-10-13 11:25:47,316 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:25:47,484 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=c0d61301-59f8-4209-8988-3f0d68747b3a&request_guid=e53a2e24-74a8-4b51-87ac-e720d1d90f02 HTTP/1.1" 200 1199
2023-10-13 11:25:47,485 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:25:47,486 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:25:47,486 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:25:47,487 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7d-0202-e9e1-0001-9cfa016961b6
2023-10-13 11:25:47,488 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7d-0202-e9e1-0001-9cfa016961b6
2023-10-13 11:25:47,488 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:25:47,489 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-10-13 11:25:47,489 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-10-13 11:25:47,489 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-10-13 11:25:47,490 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-10-13 11:25:47,490 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2023-10-13 11:25:51,116 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:25:51,118 - MainThread cursor.py:800 - execute() - INFO - query: [create schema if not exists bug_test.bug_test]
2023-10-13 11:25:51,119 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 2
2023-10-13 11:25:51,119 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 1feaee1e-2d3e-4381-88ce-2291b682c0a0
2023-10-13 11:25:51,120 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [create schema if not exists bug_test.bug_test]
2023-10-13 11:25:51,120 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:25:51,120 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:25:51,120 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[create schema if not exists bug_test.bug_test], sequence_id=[2], is_file_transfer=[False]
2023-10-13 11:25:51,121 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:25:51,121 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:25:51,122 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: a04b4abf-d514-4623-8543-8a80888ff979
2023-10-13 11:25:51,122 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:25:51,289 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=1feaee1e-2d3e-4381-88ce-2291b682c0a0&request_guid=a04b4abf-d514-4623-8543-8a80888ff979 HTTP/1.1" 200 1204
2023-10-13 11:25:51,290 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:25:51,291 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:25:51,291 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:25:51,292 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7d-0202-edd4-0001-9cfa01697062
2023-10-13 11:25:51,293 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7d-0202-edd4-0001-9cfa01697062
2023-10-13 11:25:51,293 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:25:51,294 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-10-13 11:25:51,294 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-10-13 11:25:51,294 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-10-13 11:25:51,295 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-10-13 11:25:51,296 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2023-10-13 11:26:01,541 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:26:01,542 - MainThread cursor.py:800 - execute() - INFO - query: [create or replace table bug_test.bug_test.bug_test_json(f1 number, f2 variant)]
2023-10-13 11:26:01,543 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 3
2023-10-13 11:26:01,544 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 468dd984-5956-4be1-8a67-4fedd891bce1
2023-10-13 11:26:01,545 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [create or replace table bug_test.bug_test.bug_test_json(f1 number, f2 variant)]
2023-10-13 11:26:01,546 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:26:01,547 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:26:01,547 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[create or replace table bug_test.bug_test.bug_test_json(f1 number, f2 variant)], sequence_id=[3], is_file_transfer=[False]    
2023-10-13 11:26:01,549 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:26:01,550 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:26:01,551 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: 6d8661d1-7028-4d21-b42a-f0c57c5381df
2023-10-13 11:26:01,551 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:26:01,852 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=468dd984-5956-4be1-8a67-4fedd891bce1&request_guid=6d8661d1-7028-4d21-b42a-f0c57c5381df HTTP/1.1" 200 1200
2023-10-13 11:26:01,855 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:26:01,856 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:26:01,857 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:26:01,858 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7e-0202-e9e1-0001-9cfa016961ba
2023-10-13 11:26:01,859 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7e-0202-e9e1-0001-9cfa016961ba
2023-10-13 11:26:01,860 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:26:01,861 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-10-13 11:26:01,861 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-10-13 11:26:01,862 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-10-13 11:26:01,863 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-10-13 11:26:01,864 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2023-10-13 11:26:04,522 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-10-13 11:26:07,642 - MainThread cursor.py:1131 - executemany() - DEBUG - executing many SQLs/commands
2023-10-13 11:26:07,643 - MainThread cursor.py:1171 - executemany() - DEBUG - bulk insert
2023-10-13 11:26:07,643 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:26:07,644 - MainThread connection.py:1268 - _process_params_qmarks() - DEBUG - idx: 1, type: FIXED
2023-10-13 11:26:07,646 - MainThread connection.py:1268 - _process_params_qmarks() - DEBUG - idx: 2, type: TEXT
2023-10-13 11:26:07,646 - MainThread cursor.py:800 - execute() - INFO - query: [insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)]
2023-10-13 11:26:07,647 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 4
2023-10-13 11:26:07,648 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 7b5847cb-a80d-4bdf-918a-7b25eca03af4
2023-10-13 11:26:07,648 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)]
2023-10-13 11:26:07,649 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:26:07,649 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:26:07,650 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)], sequence_id=[4], is_file_transfer=[False]       
2023-10-13 11:26:07,650 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:26:07,651 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:26:07,652 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: 5ffe0997-a9fc-4718-94b2-baa317407395
2023-10-13 11:26:07,652 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:26:08,481 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=7b5847cb-a80d-4bdf-918a-7b25eca03af4&request_guid=5ffe0997-a9fc-4718-94b2-baa317407395 HTTP/1.1" 200 1236
2023-10-13 11:26:08,483 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:26:08,484 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:26:08,485 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:26:08,486 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7e-0202-e9bf-0001-9cfa01695bfe
2023-10-13 11:26:08,487 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7e-0202-e9bf-0001-9cfa01695bfe
2023-10-13 11:26:08,488 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:26:08,488 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-10-13 11:26:08,488 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-10-13 11:26:08,489 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-10-13 11:26:08,489 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-10-13 11:26:28,590 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-10-13 11:26:28,591 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:26:28,591 - MainThread cursor.py:800 - execute() - INFO - query: [COMMIT]
2023-10-13 11:26:28,591 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 5
2023-10-13 11:26:28,591 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 5a4d47a1-cc59-4f97-bf1b-be4ef98b3864
2023-10-13 11:26:28,592 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [COMMIT]
2023-10-13 11:26:28,592 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:26:28,592 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:26:28,592 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[COMMIT], sequence_id=[5], is_file_transfer=[False]
2023-10-13 11:26:28,594 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:26:28,594 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:26:28,595 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: c7935a78-c3ba-4395-b374-3c2e3dad65c9
2023-10-13 11:26:28,595 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:26:28,884 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=5a4d47a1-cc59-4f97-bf1b-be4ef98b3864&request_guid=c7935a78-c3ba-4395-b374-3c2e3dad65c9 HTTP/1.1" 200 1200
2023-10-13 11:26:28,894 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:26:28,895 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:26:28,895 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = None, after post request
2023-10-13 11:26:28,895 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7e-0202-edd4-0001-9cfa01697066
2023-10-13 11:26:28,895 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7e-0202-edd4-0001-9cfa01697066
2023-10-13 11:26:28,899 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:26:28,900 - MainThread cursor.py:827 - execute() - DEBUG - SUCCESS
2023-10-13 11:26:28,901 - MainThread cursor.py:846 - execute() - DEBUG - PUT OR GET: False
2023-10-13 11:26:28,902 - MainThread cursor.py:941 - _init_result_and_meta() - DEBUG - Query result format: json
2023-10-13 11:26:28,903 - MainThread result_batch.py:433 - _parse() - DEBUG - parsing for result batch id: 1
2023-10-13 11:26:28,903 - MainThread cursor.py:955 - _init_result_and_meta() - INFO - Number of results in first chunk: 1
2023-10-13 11:26:32,040 - MainThread connection.py:653 - cursor() - DEBUG - cursor
2023-10-13 11:26:35,263 - MainThread cursor.py:1131 - executemany() - DEBUG - executing many SQLs/commands
2023-10-13 11:26:35,264 - MainThread cursor.py:1171 - executemany() - DEBUG - bulk insert
2023-10-13 11:26:35,264 - MainThread cursor.py:735 - execute() - DEBUG - executing SQL/command
2023-10-13 11:26:35,264 - MainThread connection.py:1268 - _process_params_qmarks() - DEBUG - idx: 1, type: FIXED
2023-10-13 11:26:35,265 - MainThread connection.py:1268 - _process_params_qmarks() - DEBUG - idx: 2, type: TEXT
2023-10-13 11:26:35,265 - MainThread cursor.py:800 - execute() - INFO - query: [insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)]
2023-10-13 11:26:35,265 - MainThread connection.py:1363 - _next_sequence_counter() - DEBUG - sequence counter: 6
2023-10-13 11:26:35,266 - MainThread cursor.py:467 - _execute_helper() - DEBUG - Request id: 53a28a28-7b35-4324-b09f-64b0f7a4c769
2023-10-13 11:26:35,266 - MainThread cursor.py:469 - _execute_helper() - DEBUG - running query [insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)]
2023-10-13 11:26:35,266 - MainThread cursor.py:476 - _execute_helper() - DEBUG - is_file_transfer: True
2023-10-13 11:26:35,267 - MainThread connection.py:1035 - cmd_query() - DEBUG - _cmd_query
2023-10-13 11:26:35,267 - MainThread connection.py:1058 - cmd_query() - DEBUG - sql=[insert into bug_test.bug_test.bug_test_json(f1, f2) select ?, parse_json(?)], sequence_id=[6], is_file_transfer=[False]       
2023-10-13 11:26:35,267 - MainThread network.py:1162 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 1/1 active sessions
2023-10-13 11:26:35,268 - MainThread network.py:847 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1
2023-10-13 11:26:35,268 - MainThread network.py:828 - add_request_guid() - DEBUG - Request guid: 83491918-2bd1-4adb-8cc9-04de14b5c471
2023-10-13 11:26:35,268 - MainThread network.py:1021 - _request_exec() - DEBUG - socket timeout: 60
2023-10-13 11:26:35,448 - MainThread connectionpool.py:456 - _make_request() - DEBUG - https://********.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=53a28a28-7b35-4324-b09f-64b0f7a4c769&request_guid=83491918-2bd1-4adb-8cc9-04de14b5c471 HTTP/1.1" 200 372
2023-10-13 11:26:35,449 - MainThread network.py:1047 - _request_exec() - DEBUG - SUCCESS
2023-10-13 11:26:35,450 - MainThread network.py:1167 - _use_requests_session() - DEBUG - Session status for SessionPool '********.snowflakecomputing.com', SessionPool 0/1 active sessions
2023-10-13 11:26:35,450 - MainThread network.py:727 - _post_request() - DEBUG - ret[code] = 002049, after post request
2023-10-13 11:26:35,450 - MainThread network.py:751 - _post_request() - DEBUG - Query id: 01af9f7e-0202-e9bf-0001-9cfa01695c02
2023-10-13 11:26:35,451 - MainThread cursor.py:807 - execute() - DEBUG - sfqid: 01af9f7e-0202-e9bf-0001-9cfa01695c02
2023-10-13 11:26:35,452 - MainThread cursor.py:813 - execute() - INFO - query execution done
2023-10-13 11:26:35,452 - MainThread cursor.py:888 - execute() - DEBUG - {'data': {'internalError': False, 'errorCode': '002049', 'age': 0, 'sqlState': '42601', 'queryId': '01af9f7e-0202-e9bf-0001-9cfa01695c02', 'line': -1, 'pos': -1, 'type': 'COMPILATION'}, 'code': '002049', 'message': 'SQL compilation error: error line 1 at position 59\nBind variable ? not set.', 'success': False, 'headers': None}
Traceback (most recent call last):
  File "C:\Program Files\WindowsApps\PythonSoftwareFoundation.Python.3.10_3.10.3056.0_x64__qbz5n2kfra8p0\lib\runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "C:\Program Files\WindowsApps\PythonSoftwareFoundation.Python.3.10_3.10.3056.0_x64__qbz5n2kfra8p0\lib\runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy\__main__.py", line 39, in <module>
    cli.main()
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy/..\debugpy\server\cli.py", line 430, in main
    run()
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy/..\debugpy\server\cli.py", line 284, in run_file
    runpy.run_path(target, run_name="__main__")
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy\_vendored\pydevd\_pydevd_bundle\pydevd_runpy.py", line 321, in run_path
    return _run_module_code(code, init_globals, run_name,
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy\_vendored\pydevd\_pydevd_bundle\pydevd_runpy.py", line 135, in _run_module_code
    _run_code(code, mod_globals, init_globals,
  File "c:\Users\Bo********\.vscode\extensions\ms-python.python-2023.18.0\pythonFiles\lib\python\debugpy\_vendored\pydevd\_pydevd_bundle\pydevd_runpy.py", line 124, in _run_code
    exec(code, run_globals)
  File "C:\Users\Bo********\source\snowflake-bug-executemany\test.py", line 46, in <module>
    snowflake_cursor.executemany(f"insert into {table_name}(f1, f2) select ?, parse_json(?)", data_to_insert)
  File "C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\snowflake\connector\cursor.py", line 1208, in executemany   
    self.execute(
  File "C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\snowflake\connector\cursor.py", line 904, in execute        
    Error.errorhandler_wrapper(self.connection, self, error_class, errvalue)
  File "C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\snowflake\connector\errors.py", line 290, in errorhandler_wrapper
    handed_over = Error.hand_to_other_handler(
  File "C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\snowflake\connector\errors.py", line 345, in hand_to_other_handler
    cursor.errorhandler(connection, cursor, error_class, error_value)
  File "C:\Users\Bo********\AppData\Local\Packages\PythonSoftwareFoundation.Python.3.10_qbz5n2kfra8p0\LocalCache\local-packages\Python310\site-packages\snowflake\connector\errors.py", line 221, in default_errorhandler
    raise error_class(
snowflake.connector.errors.ProgrammingError: 002049 (42601): 01af9f7e-0202-e9bf-0001-9cfa01695c02: SQL compilation error: error line 1 at position 59
Bind variable ? not set.
@github-actions github-actions bot changed the title executemany fails using subquery with multiple rows in bind list - throws error: "Bind variable ? not set" SNOW-940628: executemany fails using subquery with multiple rows in bind list - throws error: "Bind variable ? not set" Oct 13, 2023
@georgeb-accelins
Copy link
Author

My esteemed colleague, @cdena-accelins figured it out using this article. The solution was using both positional arguments in the select clause and a values clause with question marks for the values from the list.

    snowflake_cursor.executemany(f"insert into {table_name}(f1, f2) select $1, parse_json($2) from values (?, ?)", data_to_insert)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

1 participant