search

RedPillAnalytics / gradle-confluent

Apache License 2.0
22 stars 10 forks source link

Statements like "INSERT INTO ... (...) VALUES (...)" fail #124

Open pavlomuts opened 2 years ago

pavlomuts commented 2 years ago

Describe the bug Running the task pipelineExecute with ./gradlew pipelineExecute --pipeline-dir src/main/pipeline/failing_test --debug for the following simple KSQL script (the script is located in the folder src/main/pipeline/failing_test)

CREATE STREAM IF NOT EXISTS TEST_STREAM(
    NAME STRING KEY,
    PAYLOAD STRING
) with (kafka_topic='TEST_STREAM', value_format='json', partitions=10, replicas=1);

INSERT INTO TEST_STREAM (NAME, PAYLOAD) VALUES ('George', 'Great');

fails.

See below debug logs:

2022-06-28T17:42:33.826+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default
2022-06-28T17:42:33.847+0200 [DEBUG] [org.apache.http.client.protocol.RequestAuthCache] Auth cache not set in the context
2022-06-28T17:42:33.849+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection request: [route: {}->http://localhost:8088][total available: 0; route allocated: 0 of 20; total allocated: 0 of 200]
2022-06-28T17:42:33.873+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {}->http://localhost:8088][total available: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:33.876+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Opening connection {}->http://localhost:8088
2022-06-28T17:42:33.882+0200 [DEBUG] [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] Connecting to localhost/127.0.0.1:8088
2022-06-28T17:42:33.884+0200 [DEBUG] [org.apache.http.impl.conn.DefaultHttpClientConnectionOperator] Connection established 127.0.0.1:65466<->127.0.0.1:8088
2022-06-28T17:42:33.885+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 60000
2022-06-28T17:42:33.885+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request POST /ksql HTTP/1.1
2022-06-28T17:42:33.885+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Target auth state: UNCHALLENGED
2022-06-28T17:42:33.887+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Proxy auth state: UNCHALLENGED
2022-06-28T17:42:34.039+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Connection can be kept alive indefinitely
2022-06-28T17:42:34.052+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection [id: 0][route: {}->http://localhost:8088] can be kept alive indefinitely
2022-06-28T17:42:34.052+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:34.053+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:34.054+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:34.108+0200 [DEBUG] [com.redpillanalytics.KsqlRest] unirest response: <kong.unirest.StringResponse@50968c3f body={"@type":"statement_error","error_code":40001,"message":"Could not find STREAM/TABLE 'IF' in the Metastore","statementText":"DESCRIBE if;","entities":[]} headers=content-type: application/json
content-length: 153 statusText=Bad Request statusCode=400 parsingerror=Optional.empty config=kong.unirest.Config@7a0ebedc cookies=null>
2022-06-28T17:42:34.124+0200 [DEBUG] [com.redpillanalytics.KsqlRest] status: 400, statusText: Bad Request
2022-06-28T17:42:34.126+0200 [DEBUG] [com.redpillanalytics.KsqlRest] body: [@type:statement_error, error_code:40001, message:Could not find STREAM/TABLE 'IF' in the Metastore, statementText:DESCRIBE if;, entities:[]]
2022-06-28T17:42:34.136+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] parsed:
2022-06-28T17:42:34.136+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] sql: CREATE STREAM IF NOT EXISTS TEST_STREAM(
    NAME STRING KEY,
    PAYLOAD STRING
) with (kafka_topic='TEST_STREAM', value_format='json', partitions=10, replicas=1) 

2022-06-28T17:42:34.136+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] sql: 

INSERT INTO TEST_STREAM (NAME, PAYLOAD) VALUES ('George', 'Great') 

2022-06-28T17:42:34.140+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] cleaned:
2022-06-28T17:42:34.140+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] sql: CREATE STREAM IF NOT EXISTS TEST_STREAM( NAME STRING KEY, PAYLOAD STRING ) with (kafka_topic='TEST_STREAM', value_format='json', partitions=10, replicas=1) 

2022-06-28T17:42:34.141+0200 [DEBUG] [com.redpillanalytics.gradle.tasks.PipelineTask] sql: INSERT INTO TEST_STREAM (NAME, PAYLOAD) VALUES ('George', 'Great') 

2022-06-28T17:42:34.151+0200 [INFO] [com.redpillanalytics.KsqlRest] CREATE STREAM IF NOT EXISTS TEST_STREAM( NAME STRING KEY, PAYLOAD STRING ) with (kafka_topic='TEST_STREAM', value_format='json', partitions=10, replicas=1);
2022-06-28T17:42:34.152+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default
2022-06-28T17:42:34.152+0200 [DEBUG] [org.apache.http.client.protocol.RequestAuthCache] Auth cache not set in the context
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection request: [route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {}->http://localhost:8088][total available: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 60000
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request POST /ksql HTTP/1.1
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Target auth state: UNCHALLENGED
2022-06-28T17:42:34.153+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Proxy auth state: UNCHALLENGED
2022-06-28T17:42:35.399+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Connection can be kept alive indefinitely
2022-06-28T17:42:35.399+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection [id: 0][route: {}->http://localhost:8088] can be kept alive indefinitely
2022-06-28T17:42:35.399+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:35.400+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.400+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:35.401+0200 [DEBUG] [com.redpillanalytics.KsqlRest] unirest response: <kong.unirest.StringResponse@1830ca13 body=[{"@type":"currentStatus","statementText":"CREATE STREAM IF NOT EXISTS TEST_STREAM (NAME STRING KEY, PAYLOAD STRING) WITH (KAFKA_TOPIC='TEST_STREAM', KEY_FORMAT='KAFKA', PARTITIONS=10, REPLICAS=1, VALUE_FORMAT='JSON');","commandId":"stream/`TEST_STREAM`/create","commandStatus":{"status":"SUCCESS","message":"Stream created","queryId":null},"commandSequenceNumber":2,"warnings":[]}] headers=content-type: application/json
content-length: 382 statusText=OK statusCode=200 parsingerror=Optional.empty config=kong.unirest.Config@7a0ebedc cookies=null>
2022-06-28T17:42:35.401+0200 [DEBUG] [com.redpillanalytics.KsqlRest] status: 200, statusText: OK
2022-06-28T17:42:35.402+0200 [DEBUG] [com.redpillanalytics.KsqlRest] body: [[@type:currentStatus, statementText:CREATE STREAM IF NOT EXISTS TEST_STREAM (NAME STRING KEY, PAYLOAD STRING) WITH (KAFKA_TOPIC='TEST_STREAM', KEY_FORMAT='KAFKA', PARTITIONS=10, REPLICAS=1, VALUE_FORMAT='JSON');, commandId:stream/`TEST_STREAM`/create, commandStatus:[status:SUCCESS, message:Stream created, queryId:null], commandSequenceNumber:2, warnings:[]]]
2022-06-28T17:42:35.416+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default
2022-06-28T17:42:35.417+0200 [DEBUG] [org.apache.http.client.protocol.RequestAuthCache] Auth cache not set in the context
2022-06-28T17:42:35.417+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection request: [route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.417+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {}->http://localhost:8088][total available: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.418+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:35.418+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 60000
2022-06-28T17:42:35.418+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request GET /status/stream/TEST_STREAM/create HTTP/1.1
2022-06-28T17:42:35.418+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Target auth state: UNCHALLENGED
2022-06-28T17:42:35.419+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Proxy auth state: UNCHALLENGED
2022-06-28T17:42:35.458+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Connection can be kept alive indefinitely
2022-06-28T17:42:35.459+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection [id: 0][route: {}->http://localhost:8088] can be kept alive indefinitely
2022-06-28T17:42:35.459+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:35.460+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.460+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:35.475+0200 [DEBUG] [com.redpillanalytics.KsqlRest] Response: kong.unirest.StringResponse@cd9f79e
2022-06-28T17:42:35.484+0200 [DEBUG] [com.redpillanalytics.KsqlRest] result: [status:200, statusText:OK, error_code:[null], message:[null], statementText:[CREATE STREAM IF NOT EXISTS TEST_STREAM (NAME STRING KEY, PAYLOAD STRING) WITH (KAFKA_TOPIC='TEST_STREAM', KEY_FORMAT='KAFKA', PARTITIONS=10, REPLICAS=1, VALUE_FORMAT='JSON');], commandId:[stream/`TEST_STREAM`/create], commandStatus:[[status:SUCCESS, message:Stream created, queryId:null]], commandMessage:[[status:SUCCESS, message:Stream created, queryId:null]], body:[[@type:currentStatus, statementText:CREATE STREAM IF NOT EXISTS TEST_STREAM (NAME STRING KEY, PAYLOAD STRING) WITH (KAFKA_TOPIC='TEST_STREAM', KEY_FORMAT='KAFKA', PARTITIONS=10, REPLICAS=1, VALUE_FORMAT='JSON');, commandId:stream/`TEST_STREAM`/create, commandStatus:[status:SUCCESS, message:Stream created, queryId:null], commandSequenceNumber:2, warnings:[]]]]
2022-06-28T17:42:35.491+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default
2022-06-28T17:42:35.492+0200 [DEBUG] [org.apache.http.client.protocol.RequestAuthCache] Auth cache not set in the context
2022-06-28T17:42:35.492+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection request: [route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.492+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {}->http://localhost:8088][total available: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:35.492+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:35.493+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 60000
2022-06-28T17:42:35.493+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request POST /ksql HTTP/1.1
2022-06-28T17:42:35.493+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Target auth state: UNCHALLENGED
2022-06-28T17:42:35.493+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Proxy auth state: UNCHALLENGED
2022-06-28T17:42:36.361+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Connection can be kept alive indefinitely
2022-06-28T17:42:36.364+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection [id: 0][route: {}->http://localhost:8088] can be kept alive indefinitely
2022-06-28T17:42:36.365+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:36.365+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:36.365+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:36.367+0200 [DEBUG] [com.redpillanalytics.KsqlRest] unirest response: <kong.unirest.StringResponse@7d58da74 body=[] headers=content-type: application/json
content-length: 2 statusText=OK statusCode=200 parsingerror=Optional.empty config=kong.unirest.Config@7a0ebedc cookies=null>
2022-06-28T17:42:36.368+0200 [DEBUG] [com.redpillanalytics.KsqlRest] status: 200, statusText: OK
2022-06-28T17:42:36.368+0200 [DEBUG] [com.redpillanalytics.KsqlRest] body: []
2022-06-28T17:42:36.392+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default
2022-06-28T17:42:36.392+0200 [DEBUG] [org.apache.http.client.protocol.RequestAuthCache] Auth cache not set in the context
2022-06-28T17:42:36.392+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection request: [route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:36.392+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection leased: [id: 0][route: {}->http://localhost:8088][total available: 0; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 60000
2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request GET /status/null HTTP/1.1
2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Target auth state: UNCHALLENGED
2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Proxy auth state: UNCHALLENGED
2022-06-28T17:42:36.400+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Connection can be kept alive indefinitely
2022-06-28T17:42:36.400+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection [id: 0][route: {}->http://localhost:8088] can be kept alive indefinitely
2022-06-28T17:42:36.401+0200 [DEBUG] [org.apache.http.impl.conn.DefaultManagedHttpClientConnection] http-outgoing-0: set socket timeout to 0
2022-06-28T17:42:36.401+0200 [DEBUG] [org.apache.http.impl.conn.PoolingHttpClientConnectionManager] Connection released: [id: 0][route: {}->http://localhost:8088][total available: 1; route allocated: 1 of 20; total allocated: 1 of 200]
2022-06-28T17:42:36.401+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:36.402+0200 [LIFECYCLE] [org.gradle.internal.operations.DefaultBuildOperationRunner] 
2022-06-28T17:42:36.402+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Execute executePipelines for :pipelineExecute'
2022-06-28T17:42:36.403+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Executing task ':pipelineExecute''
2022-06-28T17:42:36.404+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Snapshot outputs after executing task ':pipelineExecute'' started
2022-06-28T17:42:36.404+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Snapshot outputs after executing task ':pipelineExecute''
2022-06-28T17:42:36.349+0200 [LIFECYCLE] [class org.gradle.internal.buildevents.TaskExecutionLogger] 
2022-06-28T17:42:36.349+0200 [LIFECYCLE] [class org.gradle.internal.buildevents.TaskExecutionLogger] > Task :pipelineExecute FAILED
2022-06-28T17:42:36.403+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Execute executePipelines for :pipelineExecute' completed
2022-06-28T17:42:36.404+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Executing task ':pipelineExecute'' completed
2022-06-28T17:42:36.404+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Snapshot outputs after executing task ':pipelineExecute'' completed
2022-06-28T17:42:36.408+0200 [DEBUG] [org.gradle.api.internal.tasks.execution.ResolveTaskExecutionModeExecuter] Removed task artifact state for task ':pipelineExecute' from context.
2022-06-28T17:42:36.409+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Task :pipelineExecute'
2022-06-28T17:42:36.409+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Task :pipelineExecute' completed
2022-06-28T17:42:36.409+0200 [INFO] [org.gradle.execution.plan.DefaultPlanExecutor] :pipelineExecute (Thread[included builds,5,main]) completed. Took 3.855 secs.
2022-06-28T17:42:36.409+0200 [DEBUG] [org.gradle.execution.plan.DefaultExecutionPlan] Node :pipelineExecute failed
2022-06-28T17:42:36.410+0200 [DEBUG] [org.gradle.execution.plan.DefaultExecutionPlan] Node producer locations for task group 0 completed, executed: false
2022-06-28T17:42:36.410+0200 [DEBUG] [org.gradle.execution.plan.DefaultExecutionPlan] Node :pipelineExecute completed, executed: true
2022-06-28T17:42:36.410+0200 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] included builds: released lock on state of build :
2022-06-28T17:42:36.411+0200 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] included builds: released lock on task execution for build :
2022-06-28T17:42:36.411+0200 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[included builds,5,main]] finished, busy: 3.855 secs, idle: 0.553 secs
2022-06-28T17:42:36.412+0200 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':',5,main]] finished, busy: 0.531 secs, idle: 3.891 secs
2022-06-28T17:42:36.414+0200 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 3,5,main]] finished, busy: 0.0 secs, idle: 4.409 secs
2022-06-28T17:42:36.415+0200 [DEBUG] [org.gradle.execution.plan.DefaultPlanExecutor] Execution worker [Thread[Execution worker for ':' Thread 2,5,main]] finished, busy: 0.0 secs, idle: 4.418 secs
2022-06-28T17:42:36.415+0200 [DEBUG] [org.gradle.execution.taskgraph.DefaultTaskExecutionGraph] Timing: Executing the DAG took 4.427 secs
2022-06-28T17:42:36.417+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Run tasks'
2022-06-28T17:42:36.417+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Run tasks' completed
2022-06-28T17:42:36.417+0200 [DEBUG] [org.gradle.internal.work.DefaultWorkerLeaseService] Worker lease root.18 completed (0 worker(s) in use)
2022-06-28T17:42:36.418+0200 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] included builds: released lock on root.18
2022-06-28T17:42:36.418+0200 [DEBUG] [org.gradle.internal.work.DefaultWorkerLeaseService] Worker lease root.1 started (1 worker(s) in use).
2022-06-28T17:42:36.418+0200 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] Daemon worker Thread 3: acquired lock on root.1
2022-06-28T17:42:36.418+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Run main tasks'
2022-06-28T17:42:36.418+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Run main tasks' completed
2022-06-28T17:42:36.444+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] 
2022-06-28T17:42:36.447+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] FAILURE: Build failed with an exception.
2022-06-28T17:42:36.447+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] 
2022-06-28T17:42:36.448+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * What went wrong:
2022-06-28T17:42:36.448+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] Execution failed for task ':pipelineExecute'.
2022-06-28T17:42:36.448+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] > java.lang.IllegalStateException: Expected BEGIN_OBJECT but was STRING at line 1 column 1 path $
2022-06-28T17:42:36.449+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] 
2022-06-28T17:42:36.449+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * Try:
2022-06-28T17:42:36.449+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] > Run with --stacktrace option to get the stack trace.
2022-06-28T17:42:36.449+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] > Run with --scan to get full insights.
2022-06-28T17:42:36.450+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] 
2022-06-28T17:42:36.450+0200 [ERROR] [org.gradle.internal.buildevents.BuildExceptionReporter] * Get more help at https://help.gradle.org
2022-06-28T17:42:36.451+0200 [WARN] [org.gradle.internal.featurelifecycle.LoggingDeprecatedFeatureHandler] 
Deprecated Gradle features were used in this build, making it incompatible with Gradle 8.0.

You can use '--warning-mode all' to show the individual deprecation warnings and determine if they come from your own scripts or plugins.

See https://docs.gradle.org/7.4.2/userguide/command_line_interface.html#sec:command_line_warnings
2022-06-28T17:42:36.451+0200 [ERROR] [org.gradle.internal.buildevents.BuildResultLogger] 
2022-06-28T17:42:36.451+0200 [ERROR] [org.gradle.internal.buildevents.BuildResultLogger] BUILD FAILED in 6s
2022-06-28T17:42:36.452+0200 [LIFECYCLE] [org.gradle.internal.buildevents.TaskExecutionStatisticsReporter] 2 actionable tasks: 2 executed
2022-06-28T17:42:36.452+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Build finished for file system watching' started
2022-06-28T17:42:36.454+0200 [INFO] [org.gradle.internal.watch.registry.impl.HierarchicalFileWatcherUpdater] Watched directory hierarchies: [/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env]
2022-06-28T17:42:36.455+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Build finished for file system watching'
2022-06-28T17:42:36.455+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Build finished for file system watching' completed
2022-06-28T17:42:36.460+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for cache directory md-supplier (/Users/pavlomuts/.gradle/caches/7.4.2/md-supplier)
2022-06-28T17:42:36.461+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on cache directory md-supplier (/Users/pavlomuts/.gradle/caches/7.4.2/md-supplier).
2022-06-28T17:42:36.463+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for execution history cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/executionHistory)
2022-06-28T17:42:36.464+0200 [DEBUG] [org.gradle.cache.internal.btree.BTreePersistentIndexedCache] Closing cache executionHistory.bin (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/executionHistory/executionHistory.bin)
2022-06-28T17:42:36.466+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on execution history cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/executionHistory).
2022-06-28T17:42:36.467+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for Build Output Cleanup Cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/buildOutputCleanup)
2022-06-28T17:42:36.467+0200 [DEBUG] [org.gradle.cache.internal.btree.BTreePersistentIndexedCache] Closing cache outputFiles.bin (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/buildOutputCleanup/outputFiles.bin)
2022-06-28T17:42:36.468+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on Build Output Cleanup Cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/buildOutputCleanup).
2022-06-28T17:42:36.469+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for cache directory md-rule (/Users/pavlomuts/.gradle/caches/7.4.2/md-rule)
2022-06-28T17:42:36.469+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on cache directory md-rule (/Users/pavlomuts/.gradle/caches/7.4.2/md-rule).
2022-06-28T17:42:36.471+0200 [DEBUG] [org.gradle.api.internal.artifacts.ivyservice.resolveengine.store.CachedStoreFactory] Resolution result cache closed. Cache reads: 0, disk reads: 0 (avg: 0.0 secs, total: 0.0 secs)
2022-06-28T17:42:36.471+0200 [DEBUG] [org.gradle.api.internal.artifacts.ivyservice.resolveengine.store.CachedStoreFactory] Resolution result cache closed. Cache reads: 0, disk reads: 0 (avg: 0.0 secs, total: 0.0 secs)
2022-06-28T17:42:36.472+0200 [DEBUG] [org.gradle.api.internal.artifacts.ivyservice.resolveengine.store.ResolutionResultsStoreFactory] Deleted 2 resolution results binary files in 0.001 secs
2022-06-28T17:42:36.472+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Completing Build operation 'Run build'
2022-06-28T17:42:36.472+0200 [DEBUG] [org.gradle.internal.operations.DefaultBuildOperationRunner] Build operation 'Run build' completed
2022-06-28T17:42:36.472+0200 [DEBUG] [org.gradle.internal.work.DefaultWorkerLeaseService] Worker lease root.1 completed (0 worker(s) in use)
2022-06-28T17:42:36.472+0200 [DEBUG] [org.gradle.internal.resources.AbstractTrackedResourceLock] Daemon worker Thread 3: released lock on root.1
2022-06-28T17:42:36.524+0200 [DEBUG] [org.gradle.deployment.internal.DefaultDeploymentRegistry] Stopping 0 deployment handles
2022-06-28T17:42:36.524+0200 [DEBUG] [org.gradle.deployment.internal.DefaultDeploymentRegistry] Stopped deployment handles
2022-06-28T17:42:36.525+0200 [DEBUG] [org.gradle.cache.internal.DefaultPersistentDirectoryStore] VCS Checkout Cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/vcs-1) has last been fully cleaned up 5 hours ago
2022-06-28T17:42:36.525+0200 [DEBUG] [org.gradle.cache.internal.DefaultCacheAccess] Cache VCS Checkout Cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/vcs-1) was closed 0 times.
2022-06-28T17:42:36.525+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for checksums cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/checksums)
2022-06-28T17:42:36.526+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on checksums cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/checksums).
2022-06-28T17:42:36.526+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for file hash cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/fileHashes)
2022-06-28T17:42:36.527+0200 [DEBUG] [org.gradle.cache.internal.btree.BTreePersistentIndexedCache] Closing cache fileHashes.bin (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/fileHashes/fileHashes.bin)
2022-06-28T17:42:36.527+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on file hash cache (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/fileHashes).
2022-06-28T17:42:36.528+0200 [DEBUG] [org.gradle.cache.internal.DefaultCacheAccess] Cache VCS metadata (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/vcsMetadata) was closed 0 times.
2022-06-28T17:42:36.529+0200 [DEBUG] [org.gradle.cache.internal.LockOnDemandCrossProcessCacheAccess] Releasing file lock for dependencies-accessors (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/dependencies-accessors)
2022-06-28T17:42:36.529+0200 [DEBUG] [org.gradle.cache.internal.DefaultFileLockManager] Releasing lock on dependencies-accessors (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/dependencies-accessors).
2022-06-28T17:42:36.530+0200 [DEBUG] [org.gradle.cache.internal.DefaultPersistentDirectoryStore] dependencies-accessors (/Users/pavlomuts/work/stream2vault/streaming-agent-2.0/agent/tests/e2e/new-env/.gradle/7.4.2/dependencies-accessors) has last been fully cleaned up 5 hours ago
2022-06-28T17:42:36.538+0200 [DEBUG] [org.gradle.launcher.daemon.server.exec.ExecuteBuild] The daemon has finished executing the build.
2022-06-28T17:42:36.734+0200 [DEBUG] [org.gradle.launcher.daemon.client.DaemonClientInputForwarder] Dispatching close input message: org.gradle.launcher.daemon.protocol.CloseInput@30d7b68f
2022-06-28T17:42:36.734+0200 [DEBUG] [org.gradle.launcher.daemon.client.DaemonClientConnection] thread 15: dispatching class org.gradle.launcher.daemon.protocol.CloseInput
2022-06-28T17:42:36.735+0200 [DEBUG] [org.gradle.launcher.daemon.client.DaemonClient] Received result Success[value=org.gradle.launcher.exec.BuildActionResult@75f5fd58] from daemon DaemonInfo{pid=30053, address=[845f90f4-4d46-4774-b405-df51882de605 port:65328, addresses:[/127.0.0.1]], state=Idle, lastBusy=1656430615783, context=DefaultDaemonContext[uid=a4c83ad6-34fb-4164-a3c4-0cb9901002e9,javaHome=/Library/Java/JavaVirtualMachines/jdk-11.0.12.jdk/Contents/Home,daemonRegistryDir=/Users/pavlomuts/.gradle/daemon,pid=30053,idleTimeout=10800000,priority=NORMAL,daemonOpts=--add-opens,java.base/java.util=ALL-UNNAMED,--add-opens,java.base/java.lang=ALL-UNNAMED,--add-opens,java.base/java.lang.invoke=ALL-UNNAMED,--add-opens,java.base/java.util=ALL-UNNAMED,--add-opens,java.prefs/java.util.prefs=ALL-UNNAMED,--add-opens,java.prefs/java.util.prefs=ALL-UNNAMED,--add-opens,java.base/java.nio.charset=ALL-UNNAMED,--add-opens,java.base/java.net=ALL-UNNAMED,--add-opens,java.base/java.util.concurrent.atomic=ALL-UNNAMED,-XX:MaxMetaspaceSize=256m,-XX:+HeapDumpOnOutOfMemoryError,-Xms256m,-Xmx512m,-Dfile.encoding=US-ASCII,-Duser.country=DE,-Duser.language=en,-Duser.variant]} (build should be done).
2022-06-28T17:42:36.735+0200 [DEBUG] [org.gradle.launcher.daemon.client.DaemonClientConnection] thread 1: dispatching class org.gradle.launcher.daemon.protocol.Finished
2022-06-28T17:42:36.735+0200 [DEBUG] [org.gradle.launcher.daemon.client.DaemonClientConnection] thread 1: connection stop
2022-06-28T17:42:36.744+0200 [LIFECYCLE] [org.gradle.launcher.cli.DebugLoggerWarningAction]

To Reproduce Run ./gradlew pipelineExecute --debug with the script mentioned above and with plugin com.redpillanalytics.gradle-confluent version 1.3.7

Expected behavior Should not fail on these type of statements.

Desktop (please complete the following information):

Additional context While looking into the source code of plugin, I noticed that after executing the ksql script the code extracts commandId. Not sure whether it is correct, but it seems that the response body for statements like INSERT INTO ... (...) VALUES (...) is empty or the statement is not executed at all, which might hint the following part of the log:

2022-06-28T17:42:36.365+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Cancelling request execution
2022-06-28T17:42:36.367+0200 [DEBUG] [com.redpillanalytics.KsqlRest] unirest response: <kong.unirest.StringResponse@7d58da74 body=[] headers=content-type: application/json
content-length: 2 statusText=OK statusCode=200 parsingerror=Optional.empty config=kong.unirest.Config@7a0ebedc cookies=null>
2022-06-28T17:42:36.368+0200 [DEBUG] [com.redpillanalytics.KsqlRest] status: 200, statusText: OK
2022-06-28T17:42:36.368+0200 [DEBUG] [com.redpillanalytics.KsqlRest] body: []
2022-06-28T17:42:36.392+0200 [DEBUG] [org.apache.http.client.protocol.RequestAddCookies] CookieSpec selected: default

Since the body is empty, the code tries to perform GET request against wrong (null) endpoint: 2022-06-28T17:42:36.393+0200 [DEBUG] [org.apache.http.impl.execchain.MainClientExec] Executing request GET /status/null HTTP/1.1 which brings to the failure of the task.

stewartbryson commented 2 years ago

I'm looking at this, but likely won't have a fix until next week. If you need it sooner, PRs are welcome. Thank you.

pavlomuts commented 2 years ago

Thanks, I can wait a week for the fix.