snowflakedb / snowflake-connector-python

Snowflake Connector for Python
https://pypi.python.org/pypi/snowflake-connector-python/
Apache License 2.0
595 stars 473 forks source link

SNOW-457892: write_pandas always give snowflake.connector.errors.OperationalError: <exception str() failed> #866

Closed jtrudel-ueat closed 3 years ago

jtrudel-ueat commented 3 years ago
  1. What version of Python are you using?

Python 3.8.10 (tags/v3.8.10:3d8993a, May 3 2021, 11:48:03) [MSC v.1928 64 bit (AMD64)]

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

Windows-10-10.0.19043-SP0

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

asn1crypto==1.4.0 azure-common==1.1.27 azure-core==1.18.0 azure-storage-blob==12.8.1 boto3==1.18.40 botocore==1.21.40 certifi==2021.5.30 cffi==1.14.6 chardet==4.0.0 charset-normalizer==2.0.4 cryptography==3.4.8 idna==3.2 isodate==0.6.0 jmespath==0.10.0 msrest==0.6.21 numpy==1.21.2 oauthlib==3.1.1 oscrypto==1.2.1 pandas==1.2.5 pyarrow==5.0.0 pycparser==2.20 pycryptodomex==3.10.1 PyJWT==2.1.0 pyOpenSSL==20.0.1 python-dateutil==2.8.2 pytz==2021.1 requests==2.26.0 requests-oauthlib==1.3.0 s3transfer==0.5.0 six==1.16.0 snowflake-connector-python==2.6.0 urllib3==1.26.6

  1. What did you do?

I'm trying to write data to a snowflake table by using write_pandas. I'm now down to adding a simple 2x2 dataframe to a 2 columns, otherwise empty table and keep getting the same error.

Full code:

import os
import pandas as pd
import snowflake.connector
from snowflake.connector.pandas_tools import write_pandas

connection = snowflake.connector.connect(
    user=os.environ["SNOWSQL_USER"],
    password=os.environ["SNOWSQL_PWD"],
    role="MY_ROLE",
    database="DB_NAME",
    warehouse="MY_WH",
    account="ACCOUNT_NAME",
    schema="SCHEMA_NAME",
)

df = pd.DataFrame([('Test1', 'Test2'), ('Test3', 'Test4')], columns=['EMAIL', 'NAME'])
write_pandas(conn=connection, df=df, table_name="TABLE_NAME", database="DB_NAME", schema="SCHEMA_NAME")
  1. What did you expect to see?

Either a successful write or more info on the issue. It used to work before, although I think I was using 2.4.6 instead of 2.6.0 before.

5.5 Error message without logs:

Traceback (most recent call last): File ".\test.py", line 17, in write_pandas(conn=connection, df=df, table_name="TABLE_NAME", database="DB_NAME", schema="SCHEMA_NAME") File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\pandas_tools.py", line 173, in write_pandas cursor.execute(upload_sql, _is_internal=True) File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\cursor.py", line 734, in execute data = sf_file_transfer_agent.result() File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\file_transfer_agent.py", line 707, in result Error.errorhandler_wrapper( File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 254, in errorhandler_wrapper handed_over = Error.hand_to_other_handler( File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 309, in hand_to_other_handler cursor.errorhandler(connection, cursor, error_class, error_value) File "C:\Users\Jérémy\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 188, in default_errorhandler raise error_class( snowflake.connector.errors.OperationalError: <exception str() failed> (snowflake) PS C:\Users\Jérémy\ueat\ai\database\python\gender_predictions

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

2021-09-13 11:25:20,013 - MainThread connection.py:270 - init() - INFO - Snowflake Connector for Python Version: 2.6.0, Python Version: 3.8.10, Platform: Windows-10-10.0.19043-SP0 2021-09-13 11:25:20,013 - MainThread connection.py:501 - connect() - DEBUG - connect 2021-09-13 11:25:20,013 - MainThread connection.py:766 - config() - DEBUG - config 2021-09-13 11:25:20,013 - MainThread connection.py:890 - 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. 2021-09-13 11:25:20,014 - MainThread connection.py:908 - config() - INFO - Setting use_openssl_only mode to False 2021-09-13 11:25:20,014 - MainThread converter.py:142 - init() - DEBUG - use_numpy: False 2021-09-13 11:25:20,015 - MainThread converter_issue23517.py:25 - init() - DEBUG - initialized 2021-09-13 11:25:20,015 - MainThread connection.py:669 - __open_connection() - DEBUG - REST API object was created: ueat.ca-central-1.aws.snowflakecomputing.com:443 2021-09-13 11:25:20,015 - MainThread auth.py:169 - authenticate() - DEBUG - authenticate 2021-09-13 11:25:20,015 - MainThread auth.py:199 - authenticate() - DEBUG - assertion content: ** 2021-09-13 11:25:20,015 - MainThread auth.py:202 - authenticate() - DEBUG - account=ueat, user=JTRUDEL, database=UEAT_AI, schema=USER_ATTRIBUTES, warehouse=AI_WH, role=UEAT_AI_ROLE, request_id=1cf1cc0f-d1a4-4340-800f-b6a975e88d7e 2021-09-13 11:25:20,015 - MainThread auth.py:235 - authenticate() - DEBUG - body['data']: {'CLIENT_APP_ID': 'PythonConnector', 'CLIENT_APP_VERSION': '2.6.0', 'SVN_REVISION': None, 'ACCOUNT_NAME': 'ueat', 'LOGIN_NAME': 'JTRUDEL', 'CLIENT_ENVIRONMENT': {'APPLICATION': 'PythonConnector', 'OS': 'Windows', 'OS_VERSION': 'Windows-10-10.0.19043-SP0', 'PYTHON_VERSION': '3.8.10', 'PYTHON_RUNTIME': 'CPython', 'PYTHON_COMPILER': 'MSC v.1928 64 bit (AMD64)', 'OCSP_MODE': 'FAIL_OPEN', 'TRACING': 10, 'LOGIN_TIMEOUT': 120, 'NETWORK_TIMEOUT': None}, 'SESSION_PARAMETERS': {'CLIENT_PREFETCH_THREADS': 4}} 2021-09-13 11:25:20,016 - MainThread retry.py:333 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None) 2021-09-13 11:25:20,016 - MainThread retry.py:333 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None) 2021-09-13 11:25:20,016 - MainThread network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 1/1 active sessions 2021-09-13 11:25:20,016 - MainThread network.py:820 - _request_exec_wrapper() - DEBUG - remaining request timeout: 120, retry cnt: 1 2021-09-13 11:25:20,016 - MainThread network.py:801 - add_request_guid() - DEBUG - Request guid: 0167e024-19d7-49dd-9374-1b7820c8f201 2021-09-13 11:25:20,017 - MainThread network.py:970 - _request_exec() - DEBUG - socket timeout: 60 2021-09-13 11:25:20,019 - MainThread connectionpool.py:971 - _new_conn() - DEBUG - Starting new HTTPS connection (1): ueat.ca-central-1.aws.snowflakecomputing.com:443 2021-09-13 11:25:20,130 - MainThread ocsp_snowflake.py:464 - reset_cache_dir() - DEBUG - cache directory: C:\Users\Jérémy\AppData\Local\Snowflake\Caches 2021-09-13 11:25:20,175 - MainThread ssl_wrap_socket.py:83 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None 2021-09-13 11:25:20,175 - MainThread ocsp_snowflake.py:506 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file://C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:20,176 - MainThread ocsp_snowflake.py:507 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 0 2021-09-13 11:25:20,176 - MainThread ocsp_snowflake.py:289 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP response cache server is enabled: http://ocsp.snowflakecomputing.com/ocsp_response_cache.json 2021-09-13 11:25:20,176 - MainThread ocsp_snowflake.py:325 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None 2021-09-13 11:25:20,177 - MainThread ocsp_snowflake.py:649 - check_ocsp_response_cache_lock_dir() - DEBUG - The cache is older than 1 day. Deleted the cache file: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:20,177 - MainThread ocsp_snowflake.py:548 - read_ocsp_response_cache_file() - DEBUG - Failed to locate OCSP response cache file. No worry. It will validate with OCSP server: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:20,177 - MainThread ocsp_snowflake.py:1063 - validate() - DEBUG - validating certificate: ueat.ca-central-1.aws.snowflakecomputing.com 2021-09-13 11:25:20,178 - MainThread ocsp_asn1crypto.py:434 - extract_certificate_chain() - DEBUG - # of certificates: 4 2021-09-13 11:25:20,178 - MainThread ocsp_asn1crypto.py:439 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('common_name', '.ca-central-1.snowflakecomputing.com')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('organizational_unit_name', 'Server CA 1B'), ('common_name', 'Amazon')]) 2021-09-13 11:25:20,179 - MainThread ocsp_asn1crypto.py:439 - 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')]) 2021-09-13 11:25:20,179 - MainThread ocsp_asn1crypto.py:439 - 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')]) 2021-09-13 11:25:20,180 - MainThread ocsp_asn1crypto.py:439 - 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')]) 2021-09-13 11:25:20,182 - MainThread ocsp_asn1crypto.py:122 - read_cert_bundle() - DEBUG - reading certificate bundle: C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\certifi\cacert.pem 2021-09-13 11:25:20,193 - MainThread ocsp_asn1crypto.py:460 - 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')]) 2021-09-13 11:25:20,194 - MainThread ocsp_snowflake.py:708 - find_cache() - DEBUG - not hit cache for subject: OrderedDict([('common_name', '.ca-central-1.snowflakecomputing.com')]) 2021-09-13 11:25:20,194 - MainThread ocsp_snowflake.py:360 - _download_ocsp_response_cache() - DEBUG - started downloading OCSP response cache file: http://ocsp.snowflakecomputing.com/ocsp_response_cache.json 2021-09-13 11:25:23,189 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:23,191 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2024-05-12 02:43:45+00:00 2021-09-13 11:25:23,193 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2024-05-12 02:47:38+00:00 2021-09-13 11:25:23,195 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-09-01 07:00:00+00:00 2021-09-13 11:25:23,198 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:23,199 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:23,212 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,220 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,222 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,223 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,224 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,225 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,226 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,227 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,228 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,229 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,231 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,232 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,233 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,234 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,237 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,238 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 19:22:35+00:00 2021-09-13 11:25:23,239 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-07-21 18:55:27+00:00 2021-09-13 11:25:23,240 - MainThread ocsp_snowflake.py:385 - _download_ocsp_response_cache() - DEBUG - ended downloading OCSP response cache file. elapsed time: 3.0455546379089355s 2021-09-13 11:25:23,240 - MainThread ocsp_snowflake.py:340 - download_cache_from_server() - DEBUG - downloaded OCSP response cache file from http://ocsp.snowflakecomputing.com/ocsp_response_cache.json 2021-09-13 11:25:23,240 - MainThread ocsp_snowflake.py:343 - download_cache_from_server() - DEBUG - # of certificates: 145 2021-09-13 11:25:23,241 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('common_name', '.ca-central-1.snowflakecomputing.com')]) 2021-09-13 11:25:23,242 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:23,242 - MainThread ocsp_asn1crypto.py:328 - process_ocsp_response() - DEBUG - Certificate is NOT attached in Basic OCSP Response. Using issuer's certificate 2021-09-13 11:25:23,242 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:23,271 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2024-05-12 02:43:45+00:00 2021-09-13 11:25:23,271 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('organizational_unit_name', 'Server CA 1B'), ('common_name', 'Amazon')]) 2021-09-13 11:25:23,272 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:23,273 - MainThread ocsp_asn1crypto.py:293 - process_ocsp_response() - DEBUG - Certificate is attached in Basic OCSP Response 2021-09-13 11:25:23,273 - MainThread ocsp_asn1crypto.py:295 - process_ocsp_response() - DEBUG - Verifying the attached certificate is signed by the issuer 2021-09-13 11:25:23,273 - MainThread ocsp_asn1crypto.py:298 - process_ocsp_response() - DEBUG - Valid Not After: 2024-05-12 02:43:45+00:00 2021-09-13 11:25:23,274 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:23,277 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2024-05-12 02:47:38+00:00 2021-09-13 11:25:23,278 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'Amazon'), ('common_name', 'Amazon Root CA 1')]) 2021-09-13 11:25:23,279 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:23,280 - MainThread ocsp_asn1crypto.py:293 - process_ocsp_response() - DEBUG - Certificate is attached in Basic OCSP Response 2021-09-13 11:25:23,280 - MainThread ocsp_asn1crypto.py:295 - process_ocsp_response() - DEBUG - Verifying the attached certificate is signed by the issuer 2021-09-13 11:25:23,280 - MainThread ocsp_asn1crypto.py:298 - process_ocsp_response() - DEBUG - Valid Not After: 2024-05-12 02:47:38+00:00 2021-09-13 11:25:23,281 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:23,285 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2022-09-01 07:00:00+00:00 2021-09-13 11:25:23,285 - MainThread ocsp_snowflake.py:682 - 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')]) 2021-09-13 11:25:23,286 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:23,287 - MainThread ocsp_asn1crypto.py:293 - process_ocsp_response() - DEBUG - Certificate is attached in Basic OCSP Response 2021-09-13 11:25:23,287 - MainThread ocsp_asn1crypto.py:295 - process_ocsp_response() - DEBUG - Verifying the attached certificate is signed by the issuer 2021-09-13 11:25:23,287 - MainThread ocsp_asn1crypto.py:298 - process_ocsp_response() - DEBUG - Valid Not After: 2022-09-01 07:00:00+00:00 2021-09-13 11:25:23,289 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:23,291 - MainThread ocsp_snowflake.py:604 - write_ocsp_response_cache_file() - DEBUG - writing OCSP response cache file to C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:23,291 - MainThread ocsp_snowflake.py:1715 - encode_ocsp_response_cache() - DEBUG - encoding OCSP response cache to JSON 2021-09-13 11:25:23,307 - MainThread ocsp_snowflake.py:1115 - _validate() - DEBUG - ok 2021-09-13 11:25:24,362 - MainThread connectionpool.py:452 - _make_request() - DEBUG - https://ueat.ca-central-1.aws.snowflakecomputing.com:443 "POST /session/v1/login-request?request_id=1cf1cc0f-d1a4-4340-800f-b6a975e88d7e&databaseName=UEAT_AI&schemaName=USER_ATTRIBUTES&warehouse=AI_WH&roleName=UEAT_AI_ROLE&request_guid=0167e024-19d7-49dd-9374-1b7820c8f201 HTTP/1.1" 200 1437 2021-09-13 11:25:24,363 - MainThread network.py:999 - _request_exec() - DEBUG - SUCCESS 2021-09-13 11:25:24,363 - MainThread network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 0/1 active sessions 2021-09-13 11:25:24,363 - MainThread network.py:708 - _post_request() - DEBUG - ret[code] = None, after post request 2021-09-13 11:25:24,364 - MainThread auth.py:354 - authenticate() - DEBUG - completed authentication 2021-09-13 11:25:24,364 - MainThread auth.py:397 - authenticate() - DEBUG - token = 2021-09-13 11:25:24,364 - MainThread auth.py:400 - authenticate() - DEBUG - master_token = ** 2021-09-13 11:25:24,365 - MainThread auth.py:404 - authenticate() - DEBUG - id_token = NULL 2021-09-13 11:25:24,365 - MainThread auth.py:408 - authenticate() - DEBUG - mfa_token = NULL 2021-09-13 11:25:24,365 - MainThread connection.py:588 - cursor() - DEBUG - cursor 2021-09-13 11:25:24,365 - MainThread pandas_tools.py:150 - write_pandas() - DEBUG - creating stage with 'create temporary stage / Python:snowflake.connector.pandas_tools.write_pandas() / "mutyx"' 2021-09-13 11:25:24,365 - MainThread cursor.py:610 - execute() - DEBUG - executing SQL/command 2021-09-13 11:25:24,366 - MainThread cursor.py:641 - execute() - DEBUG - binding: [create temporary stage / Python:snowflake.connector.pandas_tools.write_pandas()...] with input=[None], processed=[{}] 2021-09-13 11:25:24,366 - MainThread cursor.py:678 - execute() - INFO - query: [create temporary stage / Python:snowflake.connector.pandas_tools.write_pandas()...] 2021-09-13 11:25:24,366 - MainThread connection.py:1212 - _next_sequence_counter() - DEBUG - sequence counter: 1 2021-09-13 11:25:24,366 - MainThread cursor.py:440 - _execute_helper() - DEBUG - Request id: f4e90111-29eb-46d6-b1cd-189a6f4ca89d 2021-09-13 11:25:24,366 - MainThread cursor.py:443 - _execute_helper() - DEBUG - running query [create temporary stage / Python:snowflake.connector.pandas_tools.write_pandas()...] 2021-09-13 11:25:24,366 - MainThread cursor.py:452 - _execute_helper() - DEBUG - is_file_transfer: False 2021-09-13 11:25:24,366 - MainThread connection.py:935 - cmd_query() - DEBUG - _cmd_query 2021-09-13 11:25:24,366 - MainThread connection.py:958 - cmd_query() - DEBUG - sql=[create temporary stage / Python:snowflake.connector.pandas_tools.write_pandas()...], sequence_id=[1], is_file_transfer=[False] 2021-09-13 11:25:24,367 - MainThread network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 1/1 active sessions 2021-09-13 11:25:24,367 - MainThread network.py:820 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1 2021-09-13 11:25:24,367 - MainThread network.py:801 - add_request_guid() - DEBUG - Request guid: 93964340-d74b-4fbd-93b3-cedd4b263413 2021-09-13 11:25:24,367 - MainThread network.py:970 - _request_exec() - DEBUG - socket timeout: 60 2021-09-13 11:25:25,111 - MainThread connectionpool.py:452 - _make_request() - DEBUG - https://ueat.ca-central-1.aws.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=f4e90111-29eb-46d6-b1cd-189a6f4ca89d&request_guid=93964340-d74b-4fbd-93b3-cedd4b263413 HTTP/1.1" 200 1028 2021-09-13 11:25:25,111 - MainThread network.py:999 - _request_exec() - DEBUG - SUCCESS 2021-09-13 11:25:25,112 - MainThread network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 0/1 active sessions 2021-09-13 11:25:25,112 - MainThread network.py:708 - _post_request() - DEBUG - ret[code] = None, after post request 2021-09-13 11:25:25,112 - MainThread network.py:732 - _post_request() - DEBUG - Query id: 019eec7d-3200-37e1-0000-07dd0096205e 2021-09-13 11:25:25,112 - MainThread cursor.py:700 - execute() - DEBUG - sfqid: 019eec7d-3200-37e1-0000-07dd0096205e 2021-09-13 11:25:25,112 - MainThread cursor.py:702 - execute() - INFO - query execution done 2021-09-13 11:25:25,112 - MainThread cursor.py:704 - execute() - DEBUG - SUCCESS 2021-09-13 11:25:25,112 - MainThread cursor.py:707 - execute() - DEBUG - PUT OR GET: None 2021-09-13 11:25:25,113 - MainThread cursor.py:807 - _init_result_and_meta() - DEBUG - Query result format: json 2021-09-13 11:25:25,113 - MainThread result_batch.py:441 - _parse() - DEBUG - parsing for result batch id: 1 2021-09-13 11:25:25,113 - MainThread result_set.py:71 - result_set_iterator() - DEBUG - beginning to schedule result batch downloads 2021-09-13 11:25:25,139 - MainThread pandas_tools.py:172 - write_pandas() - DEBUG - uploading files with 'PUT / Python:snowflake.connector.pandas_tools.write_pandas() / 'file://C:\Users\JRMY~1\AppData\Local\Temp\tmpwif5x2xf\file0.txt' @"mutyx" PARALLEL=4' 2021-09-13 11:25:25,139 - MainThread cursor.py:610 - execute() - DEBUG - executing SQL/command 2021-09-13 11:25:25,140 - MainThread cursor.py:641 - execute() - DEBUG - binding: [PUT / Python:snowflake.connector.pandas_tools.write_pandas() / 'file://C:\Use...] with input=[None], processed=[{}] 2021-09-13 11:25:25,140 - MainThread cursor.py:678 - execute() - INFO - query: [PUT / Python:snowflake.connector.pandas_tools.write_pandas() / 'file://C:\Use...] 2021-09-13 11:25:25,140 - MainThread connection.py:1212 - _next_sequence_counter() - DEBUG - sequence counter: 2 2021-09-13 11:25:25,140 - MainThread cursor.py:440 - _execute_helper() - DEBUG - Request id: 590a4fbb-a445-441f-9528-bb6c46f826ed 2021-09-13 11:25:25,140 - MainThread cursor.py:443 - _execute_helper() - DEBUG - running query [PUT / Python:snowflake.connector.pandas_tools.write_pandas() / 'file://C:\Use...] 2021-09-13 11:25:25,140 - MainThread cursor.py:452 - _execute_helper() - DEBUG - is_file_transfer: True 2021-09-13 11:25:25,140 - MainThread connection.py:935 - cmd_query() - DEBUG - _cmd_query 2021-09-13 11:25:25,140 - MainThread connection.py:958 - cmd_query() - DEBUG - sql=[PUT / Python:snowflake.connector.pandas_tools.write_pandas() / 'file://C:\Use...], sequence_id=[2], is_file_transfer=[True] 2021-09-13 11:25:25,141 - MainThread network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 1/1 active sessions 2021-09-13 11:25:25,141 - MainThread network.py:820 - _request_exec_wrapper() - DEBUG - remaining request timeout: None, retry cnt: 1 2021-09-13 11:25:25,141 - MainThread network.py:801 - add_request_guid() - DEBUG - Request guid: dab0de26-4fb5-4079-8f29-38ab057af2cc 2021-09-13 11:25:25,141 - MainThread network.py:970 - _request_exec() - DEBUG - socket timeout: 60 2021-09-13 11:25:26,072 - MainThread connectionpool.py:452 - _make_request() - DEBUG - https://ueat.ca-central-1.aws.snowflakecomputing.com:443 "POST /queries/v1/query-request?requestId=590a4fbb-a445-441f-9528-bb6c46f826ed&request_guid=dab0de26-4fb5-4079-8f29-38ab057af2cc HTTP/1.1" 200 1212 2021-09-13 11:25:26,072 - MainThread network.py:999 - _request_exec() - DEBUG - SUCCESS 2021-09-13 11:25:26,073 - MainThread network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 0/1 active sessions 2021-09-13 11:25:26,073 - MainThread network.py:708 - _post_request() - DEBUG - ret[code] = None, after post request 2021-09-13 11:25:26,073 - MainThread network.py:732 - _post_request() - DEBUG - Query id: 019eec7d-3200-37e1-0000-07dd00962062 2021-09-13 11:25:26,073 - MainThread cursor.py:700 - execute() - DEBUG - sfqid: 019eec7d-3200-37e1-0000-07dd00962062 2021-09-13 11:25:26,073 - MainThread cursor.py:702 - execute() - INFO - query execution done 2021-09-13 11:25:26,073 - MainThread cursor.py:704 - execute() - DEBUG - SUCCESS 2021-09-13 11:25:26,073 - MainThread cursor.py:707 - execute() - DEBUG - PUT OR GET: <re.Match object; span=(0, 4), match='PUT '> 2021-09-13 11:25:26,074 - MainThread file_transfer_agent.py:808 - _init_encryption_material() - DEBUG - UPLOAD 2021-09-13 11:25:26,074 - MainThread file_transfer_agent.py:937 - _init_file_metadata() - DEBUG - command type: UPLOAD 2021-09-13 11:25:26,187 - MainThread file_transfer_agent.py:1084 - _process_file_compression_type() - DEBUG - detected the encoding parquet: file=C:\Users\JRMY~1\AppData\Local\Temp\tmpwif5x2xf\file0.txt 2021-09-13 11:25:26,188 - MainThread retry.py:333 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None) 2021-09-13 11:25:26,188 - MainThread retry.py:333 - from_int() - DEBUG - Converted retries value: 1 -> Retry(total=1, connect=None, read=None, redirect=None, status=None) 2021-09-13 11:25:26,189 - MainThread network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com', SessionPool 1/1 active sessions 2021-09-13 11:25:26,189 - MainThread storage_client.py:269 - _send_request_with_retry() - DEBUG - storage client request with session <snowflake.connector.vendored.requests.sessions.Session object at 0x0000022E6C6C7F10> 2021-09-13 11:25:26,190 - MainThread connectionpool.py:971 - _new_conn() - DEBUG - Starting new HTTPS connection (1): sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com:443 2021-09-13 11:25:28,066 - MainThread ssl_wrap_socket.py:83 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None 2021-09-13 11:25:28,066 - MainThread ocsp_snowflake.py:506 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file://C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:28,066 - MainThread ocsp_snowflake.py:507 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 145 2021-09-13 11:25:28,067 - MainThread ocsp_snowflake.py:289 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP response cache server is enabled: http://ocsp.snowflakecomputing.com/ocsp_response_cache.json 2021-09-13 11:25:28,067 - MainThread ocsp_snowflake.py:325 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None 2021-09-13 11:25:28,068 - MainThread ocsp_snowflake.py:649 - check_ocsp_response_cache_lock_dir() - DEBUG - The cache is older than 1 day. Deleted the cache file: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:28,068 - MainThread ocsp_snowflake.py:548 - read_ocsp_response_cache_file() - DEBUG - Failed to locate OCSP response cache file. No worry. It will validate with OCSP server: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:28,069 - MainThread ocsp_snowflake.py:1063 - validate() - DEBUG - validating certificate: sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com 2021-09-13 11:25:28,069 - MainThread ocsp_asn1crypto.py:434 - extract_certificate_chain() - DEBUG - # of certificates: 2 2021-09-13 11:25:28,070 - MainThread ocsp_asn1crypto.py:439 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:28,071 - MainThread ocsp_asn1crypto.py:439 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]), issuer: OrderedDict([('country_name', 'IE'), ('organization_name', 'Baltimore'), ('organizational_unit_name', 'CyberTrust'), ('common_name', 'Baltimore CyberTrust Root')]) 2021-09-13 11:25:28,073 - MainThread ocsp_asn1crypto.py:460 - create_pair_issuer_subject() - DEBUG - not found issuer_der: OrderedDict([('country_name', 'IE'), ('organization_name', 'Baltimore'), ('organizational_unit_name', 'CyberTrust'), ('common_name', 'Baltimore CyberTrust Root')]) 2021-09-13 11:25:28,075 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]) 2021-09-13 11:25:28,077 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:28,077 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:28,078 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]) 2021-09-13 11:25:28,079 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:28,079 - MainThread ocsp_asn1crypto.py:328 - process_ocsp_response() - DEBUG - Certificate is NOT attached in Basic OCSP Response. Using issuer's certificate 2021-09-13 11:25:28,079 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:28,082 - MainThread ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:28,082 - MainThread ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:28,083 - MainThread ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:28,084 - MainThread ocsp_asn1crypto.py:293 - process_ocsp_response() - DEBUG - Certificate is attached in Basic OCSP Response 2021-09-13 11:25:28,084 - MainThread ocsp_asn1crypto.py:295 - process_ocsp_response() - DEBUG - Verifying the attached certificate is signed by the issuer 2021-09-13 11:25:28,084 - MainThread ocsp_asn1crypto.py:298 - process_ocsp_response() - DEBUG - Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:28,086 - MainThread ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:28,088 - MainThread ocsp_snowflake.py:604 - write_ocsp_response_cache_file() - DEBUG - writing OCSP response cache file to C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:28,088 - MainThread ocsp_snowflake.py:1715 - encode_ocsp_response_cache() - DEBUG - encoding OCSP response cache to JSON 2021-09-13 11:25:28,104 - MainThread ocsp_snowflake.py:1115 - _validate() - DEBUG - ok 2021-09-13 11:25:28,600 - MainThread connectionpool.py:452 - _make_request() - DEBUG - https://sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com:443 "GET /?accelerate HTTP/1.1" 400 None 2021-09-13 11:25:28,602 - MainThread network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com', SessionPool 0/1 active sessions 2021-09-13 11:25:28,602 - MainThread storage_client.py:427 - delete_client_data() - DEBUG - cleaning up tmp dir: C:\Users\JRMY~1\AppData\Local\Temp\tmpkr_x6r2o 2021-09-13 11:25:28,603 - MainThread file_transfer_agent.py:403 - execute() - DEBUG - parallel=[4] 2021-09-13 11:25:28,603 - MainThread file_transfer_agent.py:415 - transfer() - DEBUG - Chunk ThreadPoolExecutor size: 4 2021-09-13 11:25:28,606 - ThreadPoolExecutor-2_0 storage_client.py:183 - preprocess() - DEBUG - Preprocessing C:\Users\JRMY~1\AppData\Local\Temp\tmpwif5x2xf\file0.txt 2021-09-13 11:25:28,607 - ThreadPoolExecutor-2_0 network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com', SessionPool 1/1 active sessions 2021-09-13 11:25:28,607 - ThreadPoolExecutor-2_0 storage_client.py:269 - _send_request_with_retry() - DEBUG - storage client request with session <snowflake.connector.vendored.requests.sessions.Session object at 0x0000022E6C6C7F10> 2021-09-13 11:25:28,609 - ThreadPoolExecutor-2_0 connectionpool.py:272 - _get_conn() - DEBUG - Resetting dropped connection: sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com 2021-09-13 11:25:31,102 - ThreadPoolExecutor-2_0 ssl_wrap_socket.py:83 - ssl_wrap_socket_with_ocsp() - DEBUG - OCSP Mode: FAIL_OPEN, OCSP response cache file name: None 2021-09-13 11:25:31,103 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:506 - reset_ocsp_response_cache_uri() - DEBUG - ocsp_response_cache_uri: file://C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:31,103 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:507 - reset_ocsp_response_cache_uri() - DEBUG - OCSP_VALIDATION_CACHE size: 145 2021-09-13 11:25:31,103 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:289 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP response cache server is enabled: http://ocsp.snowflakecomputing.com/ocsp_response_cache.json 2021-09-13 11:25:31,103 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:325 - reset_ocsp_dynamic_cache_server_url() - DEBUG - OCSP dynamic cache server RETRY URL: None 2021-09-13 11:25:31,106 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:649 - check_ocsp_response_cache_lock_dir() - DEBUG - The cache is older than 1 day. Deleted the cache file: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:31,106 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:548 - read_ocsp_response_cache_file() - DEBUG - Failed to locate OCSP response cache file. No worry. It will validate with OCSP server: C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:31,106 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:1063 - validate() - DEBUG - validating certificate: sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com 2021-09-13 11:25:31,106 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:434 - extract_certificate_chain() - DEBUG - # of certificates: 2 2021-09-13 11:25:31,107 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:439 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]), issuer: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:31,108 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:439 - extract_certificate_chain() - DEBUG - subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]), issuer: OrderedDict([('country_name', 'IE'), ('organization_name', 'Baltimore'), ('organizational_unit_name', 'CyberTrust'), ('common_name', 'Baltimore CyberTrust Root')]) 2021-09-13 11:25:31,109 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:460 - create_pair_issuer_subject() - DEBUG - not found issuer_der: OrderedDict([('country_name', 'IE'), ('organization_name', 'Baltimore'), ('organizational_unit_name', 'CyberTrust'), ('common_name', 'Baltimore CyberTrust Root')]) 2021-09-13 11:25:31,111 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]) 2021-09-13 11:25:31,115 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:31,116 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:31,117 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('state_or_province_name', 'Washington'), ('locality_name', 'Seattle'), ('organization_name', 'Amazon.com, Inc.'), ('common_name', '.s3.amazonaws.com')]) 2021-09-13 11:25:31,119 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:31,119 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:328 - process_ocsp_response() - DEBUG - Certificate is NOT attached in Basic OCSP Response. Using issuer's certificate 2021-09-13 11:25:31,120 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:31,123 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:233 - is_valid_time() - DEBUG - Verifying the attached certificate is signed by the issuer. Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:31,123 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:682 - find_cache() - DEBUG - hit cache for subject: OrderedDict([('country_name', 'US'), ('organization_name', 'DigiCert Inc'), ('organizational_unit_name', 'www.digicert.com'), ('common_name', 'DigiCert Baltimore CA-2 G2')]) 2021-09-13 11:25:31,124 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:1237 - validate_by_direct_connection() - DEBUG - using OCSP response cache 2021-09-13 11:25:31,125 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:293 - process_ocsp_response() - DEBUG - Certificate is attached in Basic OCSP Response 2021-09-13 11:25:31,125 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:295 - process_ocsp_response() - DEBUG - Verifying the attached certificate is signed by the issuer 2021-09-13 11:25:31,125 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:298 - process_ocsp_response() - DEBUG - Valid Not After: 2025-05-12 23:58:59+00:00 2021-09-13 11:25:31,127 - ThreadPoolExecutor-2_0 ocsp_asn1crypto.py:336 - process_ocsp_response() - DEBUG - Verifying the OCSP response is signed by the issuer. 2021-09-13 11:25:31,129 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:604 - write_ocsp_response_cache_file() - DEBUG - writing OCSP response cache file to C:/Users/Jérémy/AppData/Local/Snowflake/Caches/ocsp_response_cache.json 2021-09-13 11:25:31,129 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:1715 - encode_ocsp_response_cache() - DEBUG - encoding OCSP response cache to JSON 2021-09-13 11:25:31,145 - ThreadPoolExecutor-2_0 ocsp_snowflake.py:1115 - _validate() - DEBUG - ok 2021-09-13 11:25:31,937 - ThreadPoolExecutor-2_0 connectionpool.py:452 - _make_request() - DEBUG - https://sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com:443 "HEAD /xen2-s-c1ss0496/stages/82486c7e-2102-46fd-8cc3-8bd1dc6f0957/file0.txt HTTP/1.1" 400 0 2021-09-13 11:25:31,938 - ThreadPoolExecutor-2_0 network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com', SessionPool 0/1 active sessions 2021-09-13 11:25:31,938 - ThreadPoolExecutor-2_0 file_transfer_agent.py:573 - function_and_callback_wrapper() - ERROR - An exception was raised in <bound method SnowflakeStorageClient.prepare_upload of <snowflake.connector.s3_storage_client.SnowflakeS3RestClient object at 0x0000022E6C6D6C70>> Traceback (most recent call last): File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\file_transfer_agent.py", line 571, in function_and_callback_wrapper result = (True, work(*args, **kwargs)) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\storage_client.py", line 207, in prepare_upload self.preprocess() File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\storage_client.py", line 185, in preprocess self.get_file_header(meta.dst_file_name) # Check if file exists on remote File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\s3_storage_client.py", line 288, in get_file_header response.raise_for_status() File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\models.py", line 943, in raise_for_status raise HTTPError(http_error_msg, response=self) snowflake.connector.vendored.requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: https://sfc-ca-ont-ds1-customer-stage.s3.amazonaws.com/xen2-s-c1ss0496/stages/82486c7e-2102-46fd-8cc3-8bd1dc6f0957/file0.txt 2021-09-13 11:25:31,942 - ThreadPoolExecutor-2_0 file_transfer_agent.py:439 - preprocess_done_cb() - DEBUG - Failed to prepare file0.txt. 2021-09-13 11:25:31,942 - ThreadPoolExecutor-2_0 storage_client.py:239 - finish_upload() - DEBUG - C:\Users\JRMY~1\AppData\Local\Temp\tmpwif5x2xf\file0.txt upload is completed. 2021-09-13 11:25:31,943 - ThreadPoolExecutor-2_0 storage_client.py:427 - delete_client_data() - DEBUG - cleaning up tmp dir: C:\Users\JRMY~1\AppData\Local\Temp\tmpcazsmxkg 2021-09-13 11:25:31,944 - MainThread file_transfer_agent.py:698 - result() - DEBUG - raise_put_get_error: True, UPLOADED, <class 'str'>, ResultStatus.ERROR, <enum 'ResultStatus'> Traceback (most recent call last): File ".\test.py", line 26, in write_pandas(conn=connection, df=df, table_name="GENDER_PREDICTIONS", database="UEAT_AI", schema="USER_ATTRIBUTES") File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\pandas_tools.py", line 173, in write_pandas cursor.execute(upload_sql, _is_internal=True) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\cursor.py", line 734, in execute data = sf_file_transfer_agent.result() File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\file_transfer_agent.py", line 707, in result Error.errorhandler_wrapper( File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 254, in errorhandler_wrapper handed_over = Error.hand_to_other_handler( File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 309, in hand_to_other_handler cursor.errorhandler(connection, cursor, error_class, error_value) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\errors.py", line 188, in default_errorhandler raise error_class( snowflake.connector.errors.OperationalError: <exception str() failed> 2021-09-13 11:25:32,012 - MainThread connection.py:521 - close() - INFO - closed 2021-09-13 11:25:32,012 - MainThread telemetry.py:143 - close() - DEBUG - Closing telemetry client. 2021-09-13 11:25:32,012 - MainThread connection.py:524 - close() - INFO - No async queries seem to be running, deleting session 2021-09-13 11:25:32,013 - MainThread network.py:1104 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 1/1 active sessions 2021-09-13 11:25:32,013 - MainThread network.py:820 - _request_exec_wrapper() - DEBUG - remaining request timeout: 5, retry cnt: 1 2021-09-13 11:25:32,013 - MainThread network.py:801 - add_request_guid() - DEBUG - Request guid: 79282bde-6a03-4b94-8740-9d3c9e6dfde2 2021-09-13 11:25:32,013 - MainThread network.py:970 - _request_exec() - DEBUG - socket timeout: 60 2021-09-13 11:25:32,013 - MainThread network.py:1056 - _request_exec() - DEBUG - Hit retryable client error. Retrying... Ignore the following error stack: could not find io module state (interpreter shutdown?) Traceback (most recent call last): File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\network.py", line 985, in _request_exec raw_ret = session.request( File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\sessions.py", line 528, in request prep = self.prepare_request(req) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\sessions.py", line 456, in prepare_request p.prepare( File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\models.py", line 319, in prepare self.prepare_body(data, files, json) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\models.py", line 480, in prepare_body length = super_len(data) File "C:\Users\Jérémy\ueat\venv\snowflake\lib\site-packages\snowflake\connector\vendored\requests\utils.py", line 120, in super_len fileno = o.fileno() RuntimeError: could not find io module state (interpreter shutdown?) 2021-09-13 11:25:32,016 - MainThread network.py:1109 - _use_requests_session() - DEBUG - Session status for SessionPool 'ueat.ca-central-1.aws.snowflakecomputing.com', SessionPool 0/1 active sessions 2021-09-13 11:25:32,016 - MainThread network.py:708 - _post_request() - DEBUG - ret[code] = N/A, after post request 2021-09-13 11:25:32,018 - MainThread connection.py:535 - close() - DEBUG - Session is closed

sfc-gh-mkeller commented 3 years ago

Hi @jtrudel-ueat what deployment are you in? https://github.com/snowflakedb/snowflake-connector-python/issues/850#issuecomment-912105464

Please see the workarounds I posted here: https://github.com/snowflakedb/snowflake-connector-python/issues/850#issuecomment-914484810 Could you please see if option 2 fixed this issue for you?

jtrudel-ueat commented 3 years ago

Hi @sfc-gh-mkeller,

I was in deployment 2.6.0.

I can confirm that:

  1. Downgrading to 2.4.6 fixes the issue
  2. Using use_new_put_get=False while using 2.6.0 also fixes the issue.

I'll mark it as resolved then,

thank you!

sfc-gh-mkeller commented 3 years ago

Hi @sfc-gh-mkeller,

I was in deployment 2.6.0.

I can confirm that:

1. Downgrading to 2.4.6 fixes the issue

2. Using use_new_put_get=False while using 2.6.0 also fixes the issue.

I'll mark it as resolved then,

thank you!

Please, keep en eye out for version 2.6.1, once you upgrade to that version remove use_new_put_get=False and let us know if that is not working for you!

sfc-gh-mkeller commented 3 years ago

Version 2.6.1 was released 2 hours ago, please try using that @jtrudel-ueat

sfc-gh-hkapre commented 3 years ago

Please reopen if this issue is not resolved with 2.6.1