snowflakedb / gosnowflake

Go Snowflake Driver
Apache License 2.0
300 stars 125 forks source link

Issues using binding parameters in loading data from S3 #825

Closed austin-stytch closed 1 year ago

austin-stytch commented 1 year ago

Hi, I'm running into issues trying to use binding parameters, and am hoping you can either help me understand what I'm doing wrong or evaluate if this is a bug in the gosnowflake driver.

Thank you!

  1. What version of GO driver are you using? gosnowflake@v1.6.19

  2. What operating system and processor architecture are you using? Mac M1 Ventura 13.3.1

  3. What version of GO are you using? go1.20.2

4.Server version: 7.20.0

  1. What did you do?

Hi, I am trying to use binding parameters in a few different statements, and can't seem to get them to register. I have tried variations of using ?, :1, $1, etc., with and without manually quoting fields, and using identifier(?) for object names, but cannot get them to reliably work for inputs to parameters in statements. For example:

func Test_SnowflakeCreateStage(t *testing.T) {
    snowflakeConnectionString := getEnv("TEST_SNOWFLAKE_CONNECTION_STRING", "")
    if snowflakeConnectionString == "" {
        t.Skip()
        return
    }
    snowflake, err := sql.Open("snowflake", snowflakeConnectionString)
    require.NoError(t, err)

    _, err = snowflake.Exec(
        `create or replace stage uploads.test_2023_06_15.austin_test_csv_upload_v1
                    url='s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data'
                    storage_integration=s3_upload_storage_integration`,
        "austin_test_csv_upload_v1",
    )
    require.NoError(t, err)

    _, err = snowflake.Exec(
        `create or replace stage identifier(?)
                    url=s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data
                    storage_integration=s3_upload_storage_integration`,
        "uploads.test_2023_06_15.austin_test_csv_upload_v2",
    )
    require.NoError(t, err)

    _, err = snowflake.Exec(
        `create or replace stage identifier(?)
                    url=?
                    storage_integration=s3_upload_storage_integration`,
        "uploads.test_2023_06_15.austin_test_csv_upload_v3",
        "s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data",
    )
    require.NoError(t, err)
}

functions for the first two, and for the last one with url=? fails with:

            Error:          Received unexpected error:
                            001008 (22023): SQL compilation error:
                            invalid value [?] for parameter 'URL'

e.g., I get the first two stages and not the third:

INTERNALTOOLS_PROD#REPORTING@UPLOADS.TEST_2023_06_15>show stages
                                                     ;
+-------------------------------+---------------------------+---------------+-----------------+----------------------------------------------------------------------------------+-----------------+--------------------+---------------+---------+-----------+----------+-------+----------------------+-------------------------------+
| created_on                    | name                      | database_name | schema_name     | url                                                                              | has_credentials | has_encryption_key | owner         | comment | region    | type     | cloud | notification_channel | storage_integration           |
|-------------------------------+---------------------------+---------------+-----------------+----------------------------------------------------------------------------------+-----------------+--------------------+---------------+---------+-----------+----------+-------+----------------------+-------------------------------|
| 2023-06-15 13:08:55.691 -0700 | AUSTIN_TEST_CSV_UPLOAD_V1 | UPLOADS       | TEST_2023_06_15 | s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data | N               | N                  | INTERNALTOOLS |         | us-west-2 | EXTERNAL | AWS   | NULL                 | S3_UPLOAD_STORAGE_INTEGRATION |
| 2023-06-15 13:08:55.902 -0700 | AUSTIN_TEST_CSV_UPLOAD_V2 | UPLOADS       | TEST_2023_06_15 | s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data | N               | N                  | INTERNALTOOLS |         | us-west-2 | EXTERNAL | AWS   | NULL                 | S3_UPLOAD_STORAGE_INTEGRATION |
+-------------------------------+---------------------------+---------------+-----------------+----------------------------------------------------------------------------------+-----------------+--------------------+---------------+---------+-----------+----------+-------+----------------------+-------------------------------+
2 Row(s) produced. Time Elapsed: 0.463s
  1. What did you expect to see?

I expect to see a stage AUSTIN_TEST_CSV_UPLOAD_V3 identical to the other ones

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

    I will try this out

  2. What is your Snowflake account identifier, if any?

Can be provided in private communications if needed

I'm having broad issues with binding parameters. As an additional example, if I try to do something like

    inferSchemaQuery, err := s.snowflake.PrepareContext(
        ctx,
        `select * from table(infer_schema(location=>'@uploads.austin_test.csv_upload', file_format=>'uploads.public.csv'));`,
    )
    inferSchemaResult, err := inferSchemaQuery.QueryContext(ctx)

it works fine, but not as

    inferSchemaQuery, err := s.snowflake.PrepareContext(
        ctx,
        `select * from table(infer_schema(location=>?, file_format=>?));`,
    )
    inferSchemaResult, err := inferSchemaQuery.QueryContext(ctx, tablename, fileFormat)

similarly trying different permutations of ?, '?', $1, :1, etc.

austin-stytch commented 1 year ago

Debug log:

func Test_SnowflakeCreateStage(t *testing.T) {
    snowflakeConnectionString := getEnv("TEST_SNOWFLAKE_CONNECTION_STRING", "")
    if snowflakeConnectionString == "" {
        t.Skip()
        return
    }
    snowflake, err := sql.Open("snowflake", snowflakeConnectionString)
    require.NoError(t, err)

    buf := &bytes.Buffer{}
    testlog := sf.CreateDefaultLogger()
    testlog.SetLogLevel("debug")
    testlog.SetOutput(buf)
    sf.SetLogger(&testlog)

    _, err = snowflake.Exec(
        `create or replace stage identifier(?)
                    url=?
                    storage_integration=s3_upload_storage_integration`,
        "uploads.test_2023_06_15.austin_test_csv_upload_v4",
        "s3://stytch-snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data",
    )

    log.Print(buf.String())

    require.NoError(t, err)
}

=>

==== RUN   Test_SnowflakeCreateStage
2023/06/15 14:25:40 time="2023-06-15T14:25:39-06:00" level=info msg=Open func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="Query String: warehouse=REPORTING\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg=OpenWithConfig func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="Authenticating via SNOWFLAKE" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg="Username and password" func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="PARAMS for Auth: &map[warehouse:[REPORTING]], https, <redacted>.snowflakecomputing.com, 443, 1m0s, SNOWFLAKE" func=gosnowflake.authenticate file="auth.go:403"
time="2023-06-15T14:25:39-06:00" level=info msg="full URL: https://<redacted>.snowflakecomputing.com:443/session/v1/login-request?requestId=dafc55e6-8976-4000-5cef-e5e29354f50e&request_guid=0b57fb28-8378-4e87-48ee-e3e215091528&warehouse=REPORTING" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg="retryHTTP.totalTimeout: 1m0s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:39-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="Subject: CN=*.us-west-2.snowflakecomputing.com, Issuer: CN=Amazon RSA 2048 M01,O=Amazon,C=US\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="Subject: CN=Amazon RSA 2048 M01,O=Amazon,C=US, Issuer: CN=Amazon Root CA 1,O=Amazon,C=US\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="Authentication SUCCESS" func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:40-06:00" level=info msg="params: []gosnowflake.nameValueParameter{gosnowflake.nameValueParameter{Name:\"TIMESTAMP_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_PREFETCH_THREADS\", Value:4}, gosnowflake.nameValueParameter{Name:\"TIME_OUTPUT_FORMAT\", Value:\"HH24:MI:SS\"}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_TZ_OUTPUT_FORMAT\", Value:\"\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_CHUNK_SIZE\", Value:160}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_KEEP_ALIVE\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_METADATA_USE_SESSION_DATABASE\", Value:false}, gosnowflake.nameValueParameter{Name:\"QUERY_CONTEXT_CACHE_SIZE\", Value:5}, gosnowflake.nameValueParameter{Name:\"CLIENT_OUT_OF_BAND_TELEMETRY_ENABLED\", Value:false}, gosnowflake.nameValueParameter{Name:\"ENABLE_STAGE_S3_PRIVATELINK_FOR_US_EAST_1\", Value:false}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_NTZ_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD HH24:MI:SS.FF3\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_PREFETCH_THREADS\", Value:1}, gosnowflake.nameValueParameter{Name:\"CLIENT_METADATA_REQUEST_USE_CONNECTION_CTX\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_HONOR_CLIENT_TZ_FOR_TIMESTAMP_NTZ\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_MEMORY_LIMIT\", Value:1536}, gosnowflake.nameValueParameter{Name:\"CLIENT_TIMESTAMP_TYPE_MAPPING\", Value:\"TIMESTAMP_LTZ\"}, gosnowflake.nameValueParameter{Name:\"TIMEZONE\", Value:\"America/Los_Angeles\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_PREFETCH_SLOTS\", Value:2}, gosnowflake.nameValueParameter{Name:\"CLIENT_TELEMETRY_ENABLED\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_USE_V1_QUERY_API\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_DISABLE_INCIDENTS\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_COLUMN_CASE_INSENSITIVE\", Value:false}, gosnowflake.nameValueParameter{Name:\"BINARY_OUTPUT_FORMAT\", Value:\"HEX\"}, gosnowflake.nameValueParameter{Name:\"CSV_TIMESTAMP_FORMAT\", Value:\"\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_ENABLE_LOG_INFO_STATEMENT_PARAMETERS\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_TELEMETRY_SESSIONLESS_ENABLED\", Value:true}, gosnowflake.nameValueParameter{Name:\"DATE_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_CONSENT_CACHE_ID_TOKEN\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_FORCE_PROTECT_ID_TOKEN\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_STAGE_ARRAY_BINDING_THRESHOLD\", Value:65280}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_KEEP_ALIVE_HEARTBEAT_FREQUENCY\", Value:3600}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_CLONE\", Value:false}, gosnowflake.nameValueParameter{Name:\"AUTOCOMMIT\", Value:true}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_LTZ_OUTPUT_FORMAT\", Value:\"\"}}" func="gosnowflake.(*snowflakeConn).populateSessionParameters" file="connection_util.go:137"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_OUTPUT_FORMAT, value: YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_PREFETCH_THREADS, value: 4" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIME_OUTPUT_FORMAT, value: HH24:MI:SS" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_TZ_OUTPUT_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_CHUNK_SIZE, value: 160" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_KEEP_ALIVE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_METADATA_USE_SESSION_DATABASE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: QUERY_CONTEXT_CACHE_SIZE, value: 5" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_OUT_OF_BAND_TELEMETRY_ENABLED, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: ENABLE_STAGE_S3_PRIVATELINK_FOR_US_EAST_1, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_NTZ_OUTPUT_FORMAT, value: YYYY-MM-DD HH24:MI:SS.FF3" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_PREFETCH_THREADS, value: 1" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_METADATA_REQUEST_USE_CONNECTION_CTX, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_HONOR_CLIENT_TZ_FOR_TIMESTAMP_NTZ, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_MEMORY_LIMIT, value: 1536" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TIMESTAMP_TYPE_MAPPING, value: TIMESTAMP_LTZ" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMEZONE, value: America/Los_Angeles" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_PREFETCH_SLOTS, value: 2" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TELEMETRY_ENABLED, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_USE_V1_QUERY_API, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_DISABLE_INCIDENTS, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_COLUMN_CASE_INSENSITIVE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: BINARY_OUTPUT_FORMAT, value: HEX" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CSV_TIMESTAMP_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_ENABLE_LOG_INFO_STATEMENT_PARAMETERS, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TELEMETRY_SESSIONLESS_ENABLED, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: DATE_OUTPUT_FORMAT, value: YYYY-MM-DD" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_CONSENT_CACHE_ID_TOKEN, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_FORCE_PROTECT_ID_TOKEN, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_STAGE_ARRAY_BINDING_THRESHOLD, value: 65280" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_KEEP_ALIVE_HEARTBEAT_FREQUENCY, value: 3600" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_CLONE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: AUTOCOMMIT, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_LTZ_OUTPUT_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="sending 1 logs to telemetry. inband telemetry payload being sent: {\"logs\":[{\"timestamp\":1686860740617,\"message\":{\"DriverType\":\"Go\",\"DriverVersion\":\"1.6.19\",\"autocommit\":\"true\",\"binary_output_format\":\"HEX\",\"client_consent_cache_id_token\":\"false\",\"client_disable_incidents\":\"true\",\"client_enable_log_info_statement_parameters\":\"false\",\"client_force_protect_id_token\":\"true\",\"client_honor_client_tz_for_timestamp_ntz\":\"true\",\"client_memory_limit\":\"1536\",\"client_metadata_request_use_connection_ctx\":\"false\",\"client_metadata_use_session_database\":\"false\",\"client_out_of_band_telemetry_enabled\":\"false\",\"client_prefetch_threads\":\"4\",\"client_result_chunk_size\":\"160\",\"client_result_column_case_insensitive\":\"false\",\"client_result_prefetch_slots\":\"2\",\"client_result_prefetch_threads\":\"1\",\"client_session_clone\":\"false\",\"client_session_keep_alive\":\"false\",\"client_session_keep_alive_heartbeat_frequency\":\"3600\",\"client_stage_array_binding_threshold\":\"65280\",\"client_telemetry_enabled\":\"true\",\"client_telemetry_sessionless_enabled\":\"true\",\"client_timestamp_type_mapping\":\"TIMESTAMP_LTZ\",\"client_use_v1_query_api\":\"true\",\"csv_timestamp_format\":\"\",\"date_output_format\":\"YYYY-MM-DD\",\"enable_stage_s3_privatelink_for_us_east_1\":\"false\",\"query_context_cache_size\":\"5\",\"source\":\"golang_driver\",\"time_output_format\":\"HH24:MI:SS\",\"timestamp_ltz_output_format\":\"\",\"timestamp_ntz_output_format\":\"YYYY-MM-DD HH24:MI:SS.FF3\",\"timestamp_output_format\":\"YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM\",\"timestamp_tz_output_format\":\"\",\"timezone\":\"America/Los_Angeles\",\"type\":\"client_connection_parameters\"}}]}" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="retryHTTP.totalTimeout: 10s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:40-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="successfully uploaded metrics to telemetry" func="gosnowflake.(*defaultLogger).Debug" file="log.go:146"
time="2023-06-15T14:25:40-06:00" level=info msg="Exec: \"create or replace stage identifier(?)\\n\\t\\t\\t\\t\\turl=?\\n\\t\\t\\t\\t\\tstorage_integration=s3_upload_storage_integration\", [{ 1 uploads.test_2023_06_15.austin_test_csv_upload_v4} { 2 s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data}]" func="gosnowflake.(*snowflakeConn).ExecContext" file="connection.go:232"
time="2023-06-15T14:25:40-06:00" level=info msg="parameters: map[]" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:92"
time="2023-06-15T14:25:40-06:00" level=debug msg="TYPE: string, uploads.test_2023_06_15.austin_test_csv_upload_v4" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="TYPE: string, s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="bindings: map[1:{TEXT 0x14000eb63b0} 2:{TEXT 0x14000eb6470}]" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:101"
time="2023-06-15T14:25:40-06:00" level=info msg="params: &map[]" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="retryHTTP.totalTimeout: 0s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:40-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="postQuery: resp: &{200 OK 200 HTTP/1.1 1 1 map[Cache-Control:[no-cache, no-store] Connection:[keep-alive] Content-Length:[357] Content-Type:[application/json] Date:[Thu, 15 Jun 2023 20:25:40 GMT] Expect-Ct:[enforce, max-age=3600] Strict-Transport-Security:[max-age=31536000] Vary:[Accept-Encoding, User-Agent] X-Content-Type-Options:[nosniff] X-Country:[United States] X-Frame-Options:[deny] X-Xss-Protection:[1; mode=block]] 0x14000e6a920 357 [] false false map[] 0x14000f52200 0x140000cb6b0}" func=gosnowflake.postRestfulQueryHelper file="restful.go:216"
time="2023-06-15T14:25:40-06:00" level=info msg="Success: false, Code: 1008" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:131"
time="2023-06-15T14:25:40-06:00" level=info msg="error: 001008 (22023): SQL compilation error:\ninvalid value [?] for parameter 'URL'" func="gosnowflake.(*snowflakeConn).ExecContext" file="connection.go:242"
== RUN   Test_SnowflakeCreateStage
2023/06/15 14:25:40 time="2023-06-15T14:25:39-06:00" level=info msg=Open func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="Query String: warehouse=REPORTING\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg=OpenWithConfig func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="Authenticating via SNOWFLAKE" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg="Username and password" func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:39-06:00" level=info msg="PARAMS for Auth: &map[warehouse:[REPORTING]], https, <redacted>.snowflakecomputing.com, 443, 1m0s, SNOWFLAKE" func=gosnowflake.authenticate file="auth.go:403"
time="2023-06-15T14:25:39-06:00" level=info msg="full URL: https://<redacted>.snowflakecomputing.com:443/session/v1/login-request?requestId=dafc55e6-8976-4000-5cef-e5e29354f50e&request_guid=0b57fb28-8378-4e87-48ee-e3e215091528&warehouse=REPORTING" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:39-06:00" level=info msg="retryHTTP.totalTimeout: 1m0s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:39-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="Subject: CN=*.us-west-2.snowflakecomputing.com, Issuer: CN=Amazon RSA 2048 M01,O=Amazon,C=US\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="Subject: CN=Amazon RSA 2048 M01,O=Amazon,C=US, Issuer: CN=Amazon Root CA 1,O=Amazon,C=US\n" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="Authentication SUCCESS" func="gosnowflake.(*defaultLogger).Info" file="log.go:150"
time="2023-06-15T14:25:40-06:00" level=info msg="params: []gosnowflake.nameValueParameter{gosnowflake.nameValueParameter{Name:\"TIMESTAMP_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_PREFETCH_THREADS\", Value:4}, gosnowflake.nameValueParameter{Name:\"TIME_OUTPUT_FORMAT\", Value:\"HH24:MI:SS\"}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_TZ_OUTPUT_FORMAT\", Value:\"\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_CHUNK_SIZE\", Value:160}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_KEEP_ALIVE\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_METADATA_USE_SESSION_DATABASE\", Value:false}, gosnowflake.nameValueParameter{Name:\"QUERY_CONTEXT_CACHE_SIZE\", Value:5}, gosnowflake.nameValueParameter{Name:\"CLIENT_OUT_OF_BAND_TELEMETRY_ENABLED\", Value:false}, gosnowflake.nameValueParameter{Name:\"ENABLE_STAGE_S3_PRIVATELINK_FOR_US_EAST_1\", Value:false}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_NTZ_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD HH24:MI:SS.FF3\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_PREFETCH_THREADS\", Value:1}, gosnowflake.nameValueParameter{Name:\"CLIENT_METADATA_REQUEST_USE_CONNECTION_CTX\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_HONOR_CLIENT_TZ_FOR_TIMESTAMP_NTZ\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_MEMORY_LIMIT\", Value:1536}, gosnowflake.nameValueParameter{Name:\"CLIENT_TIMESTAMP_TYPE_MAPPING\", Value:\"TIMESTAMP_LTZ\"}, gosnowflake.nameValueParameter{Name:\"TIMEZONE\", Value:\"America/Los_Angeles\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_PREFETCH_SLOTS\", Value:2}, gosnowflake.nameValueParameter{Name:\"CLIENT_TELEMETRY_ENABLED\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_USE_V1_QUERY_API\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_DISABLE_INCIDENTS\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_RESULT_COLUMN_CASE_INSENSITIVE\", Value:false}, gosnowflake.nameValueParameter{Name:\"BINARY_OUTPUT_FORMAT\", Value:\"HEX\"}, gosnowflake.nameValueParameter{Name:\"CSV_TIMESTAMP_FORMAT\", Value:\"\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_ENABLE_LOG_INFO_STATEMENT_PARAMETERS\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_TELEMETRY_SESSIONLESS_ENABLED\", Value:true}, gosnowflake.nameValueParameter{Name:\"DATE_OUTPUT_FORMAT\", Value:\"YYYY-MM-DD\"}, gosnowflake.nameValueParameter{Name:\"CLIENT_CONSENT_CACHE_ID_TOKEN\", Value:false}, gosnowflake.nameValueParameter{Name:\"CLIENT_FORCE_PROTECT_ID_TOKEN\", Value:true}, gosnowflake.nameValueParameter{Name:\"CLIENT_STAGE_ARRAY_BINDING_THRESHOLD\", Value:65280}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_KEEP_ALIVE_HEARTBEAT_FREQUENCY\", Value:3600}, gosnowflake.nameValueParameter{Name:\"CLIENT_SESSION_CLONE\", Value:false}, gosnowflake.nameValueParameter{Name:\"AUTOCOMMIT\", Value:true}, gosnowflake.nameValueParameter{Name:\"TIMESTAMP_LTZ_OUTPUT_FORMAT\", Value:\"\"}}" func="gosnowflake.(*snowflakeConn).populateSessionParameters" file="connection_util.go:137"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_OUTPUT_FORMAT, value: YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_PREFETCH_THREADS, value: 4" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIME_OUTPUT_FORMAT, value: HH24:MI:SS" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_TZ_OUTPUT_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_CHUNK_SIZE, value: 160" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_KEEP_ALIVE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_METADATA_USE_SESSION_DATABASE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: QUERY_CONTEXT_CACHE_SIZE, value: 5" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_OUT_OF_BAND_TELEMETRY_ENABLED, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: ENABLE_STAGE_S3_PRIVATELINK_FOR_US_EAST_1, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_NTZ_OUTPUT_FORMAT, value: YYYY-MM-DD HH24:MI:SS.FF3" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_PREFETCH_THREADS, value: 1" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_METADATA_REQUEST_USE_CONNECTION_CTX, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_HONOR_CLIENT_TZ_FOR_TIMESTAMP_NTZ, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_MEMORY_LIMIT, value: 1536" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TIMESTAMP_TYPE_MAPPING, value: TIMESTAMP_LTZ" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMEZONE, value: America/Los_Angeles" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_PREFETCH_SLOTS, value: 2" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TELEMETRY_ENABLED, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_USE_V1_QUERY_API, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_DISABLE_INCIDENTS, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_RESULT_COLUMN_CASE_INSENSITIVE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: BINARY_OUTPUT_FORMAT, value: HEX" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CSV_TIMESTAMP_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_ENABLE_LOG_INFO_STATEMENT_PARAMETERS, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_TELEMETRY_SESSIONLESS_ENABLED, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: DATE_OUTPUT_FORMAT, value: YYYY-MM-DD" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_CONSENT_CACHE_ID_TOKEN, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_FORCE_PROTECT_ID_TOKEN, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_STAGE_ARRAY_BINDING_THRESHOLD, value: 65280" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_KEEP_ALIVE_HEARTBEAT_FREQUENCY, value: 3600" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: CLIENT_SESSION_CLONE, value: false" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: AUTOCOMMIT, value: true" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="parameter. name: TIMESTAMP_LTZ_OUTPUT_FORMAT, value: " func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="sending 1 logs to telemetry. inband telemetry payload being sent: {\"logs\":[{\"timestamp\":1686860740617,\"message\":{\"DriverType\":\"Go\",\"DriverVersion\":\"1.6.19\",\"autocommit\":\"true\",\"binary_output_format\":\"HEX\",\"client_consent_cache_id_token\":\"false\",\"client_disable_incidents\":\"true\",\"client_enable_log_info_statement_parameters\":\"false\",\"client_force_protect_id_token\":\"true\",\"client_honor_client_tz_for_timestamp_ntz\":\"true\",\"client_memory_limit\":\"1536\",\"client_metadata_request_use_connection_ctx\":\"false\",\"client_metadata_use_session_database\":\"false\",\"client_out_of_band_telemetry_enabled\":\"false\",\"client_prefetch_threads\":\"4\",\"client_result_chunk_size\":\"160\",\"client_result_column_case_insensitive\":\"false\",\"client_result_prefetch_slots\":\"2\",\"client_result_prefetch_threads\":\"1\",\"client_session_clone\":\"false\",\"client_session_keep_alive\":\"false\",\"client_session_keep_alive_heartbeat_frequency\":\"3600\",\"client_stage_array_binding_threshold\":\"65280\",\"client_telemetry_enabled\":\"true\",\"client_telemetry_sessionless_enabled\":\"true\",\"client_timestamp_type_mapping\":\"TIMESTAMP_LTZ\",\"client_use_v1_query_api\":\"true\",\"csv_timestamp_format\":\"\",\"date_output_format\":\"YYYY-MM-DD\",\"enable_stage_s3_privatelink_for_us_east_1\":\"false\",\"query_context_cache_size\":\"5\",\"source\":\"golang_driver\",\"time_output_format\":\"HH24:MI:SS\",\"timestamp_ltz_output_format\":\"\",\"timestamp_ntz_output_format\":\"YYYY-MM-DD HH24:MI:SS.FF3\",\"timestamp_output_format\":\"YYYY-MM-DD HH24:MI:SS.FF3 TZHTZM\",\"timestamp_tz_output_format\":\"\",\"timezone\":\"America/Los_Angeles\",\"type\":\"client_connection_parameters\"}}]}" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="retryHTTP.totalTimeout: 10s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:40-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="successfully uploaded metrics to telemetry" func="gosnowflake.(*defaultLogger).Debug" file="log.go:146"
time="2023-06-15T14:25:40-06:00" level=info msg="Exec: \"create or replace stage identifier(?)\\n\\t\\t\\t\\t\\turl=?\\n\\t\\t\\t\\t\\tstorage_integration=s3_upload_storage_integration\", [{ 1 uploads.test_2023_06_15.austin_test_csv_upload_v4} { 2 s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data}]" func="gosnowflake.(*snowflakeConn).ExecContext" file="connection.go:232"
time="2023-06-15T14:25:40-06:00" level=info msg="parameters: map[]" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:92"
time="2023-06-15T14:25:40-06:00" level=debug msg="TYPE: string, uploads.test_2023_06_15.austin_test_csv_upload_v4" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=debug msg="TYPE: string, s3://snowflake-upload/austin_test_v2_csv_upload__2023_06_15_14_04_12/data" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="bindings: map[1:{TEXT 0x14000eb63b0} 2:{TEXT 0x14000eb6470}]" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:101"
time="2023-06-15T14:25:40-06:00" level=info msg="params: &map[]" func="gosnowflake.(*defaultLogger).Infof" file="log.go:106"
time="2023-06-15T14:25:40-06:00" level=info msg="retryHTTP.totalTimeout: 0s" func="gosnowflake.(*retryHTTP).execute" file="retry.go:211"
time="2023-06-15T14:25:40-06:00" level=debug msg="retry count: 0" func="gosnowflake.(*defaultLogger).Debugf" file="log.go:102"
time="2023-06-15T14:25:40-06:00" level=info msg="postQuery: resp: &{200 OK 200 HTTP/1.1 1 1 map[Cache-Control:[no-cache, no-store] Connection:[keep-alive] Content-Length:[357] Content-Type:[application/json] Date:[Thu, 15 Jun 2023 20:25:40 GMT] Expect-Ct:[enforce, max-age=3600] Strict-Transport-Security:[max-age=31536000] Vary:[Accept-Encoding, User-Agent] X-Content-Type-Options:[nosniff] X-Country:[United States] X-Frame-Options:[deny] X-Xss-Protection:[1; mode=block]] 0x14000e6a920 357 [] false false map[] 0x14000f52200 0x140000cb6b0}" func=gosnowflake.postRestfulQueryHelper file="restful.go:216"
time="2023-06-15T14:25:40-06:00" level=info msg="Success: false, Code: 1008" func="gosnowflake.(*snowflakeConn).exec" file="connection.go:131"
time="2023-06-15T14:25:40-06:00" level=info msg="error: 001008 (22023): SQL compilation error:\ninvalid value [?] for parameter 'URL'" func="gosnowflake.(*snowflakeConn).ExecContext" file="connection.go:242"
sfc-gh-dszmolka commented 1 year ago

hi and thank you for raising this issue! did some research internally and confirmed with the folks specializing in the Snowflake backend engine that this is not supported yet by the backend, so it's not a driver issue. needless to say, of course other customers would be keen using such an option so hopefully it gets implemented in the backend sooner or later.

closing out this one for now as there's nothing at this moment we can do in the driver.

austin-stytch commented 1 year ago

Ah gotcha, thanks for the context. Would it be helpful to open an issue somewhere else? Do you otherwise have a recommendation on how to build this sort of workflow programmatically, or is the last resource to use golang string interpolation and roll your own sql injection mitigation?

sfc-gh-dszmolka commented 1 year ago

i think for these parameters you'll indeed need to resort to some kind of custom sql injection prevention logic. as for the product improvement (for the Snowflake engine to support this kind of binding) , if you're a Snowflake customer, you can reach out to your Sales rep. to make them aware of your requirement and they can take the rest of the steps to transform it into an actual tracked product requirement.

austin-stytch commented 1 year ago

Makes sense, thanks!