Step: When creating the connection to a new source or destination
Description:
Connection tests fails without error instead of checking image availability/pulling image.
NB: I need to request all my network openings from IT, so it might be a fw/routing issue. I should be able to access any https, but might miss ssh and more obscure ports/protocols
2023-02-24 09:32:49 INFO i.a.w.t.TemporalAttemptExecution(get):138 - Cloud storage job log path: /workspace/41a0d0ed-961c-42d7-9130-6b533d235309/0/logs.log
2023-02-24 09:32:49 INFO i.a.w.t.TemporalAttemptExecution(get):141 - Executing worker wrapper. Airbyte version: 0.40.32
2023-02-24 09:32:49 INFO i.a.a.c.AirbyteApiClient(retryWithJitter):172 - Attempt 0 to save workflow id for cancellation
2023-02-24 09:32:49 INFO i.a.c.i.LineGobbler(voidCall):114 -
2023-02-24 09:32:49 INFO i.a.w.p.KubeProcessFactory(create):98 - Attempting to start pod = source-mssql-check-41a0d0ed-961c-42d7-9130-6b533d235309-0-aaori for airbyte/source-mssql:0.4.28 with resources io.airbyte.config.ResourceRequirements@5ca586f[cpuRequest=,cpuLimit=,memoryRequest=,memoryLimit=] and allowedHosts null
2023-02-24 09:32:49 INFO i.a.c.i.LineGobbler(voidCall):114 - ----- START CHECK -----
2023-02-24 09:32:49 INFO i.a.c.i.LineGobbler(voidCall):114 -
This occured in the worker log (not the same try, but after trying again). Do I read this correctly that the failure is caused by the fact that the worker cannot connect to the temporal server?
2023-02-24T11:13:38.616810895Z 2023-02-24 11:13:38 e[33mWARNe[m i.t.i.s.WorkflowExecuteRunnable(throwAndFailWorkflowExecution):134 - Workflow execution failure WorkflowId='038496e7-8574-44c0-b7cc-25d941f39670', RunId=03fde982-a8fd-4454-b270-9c45574cbbb8, WorkflowType='CheckConnectionWorkflow'
2023-02-24T11:13:38.616846695Z io.temporal.failure.ActivityFailure: scheduledEventId=6, startedEventId=7, activityType='RunWithJobOutput', activityId='5c3a9cc7-9fb2-3c44-8838-e375ab84d03a', identity='', retryState=RETRY_STATE_NON_RETRYABLE_FAILURE
2023-02-24T11:13:38.616852395Z at java.lang.Thread.getStackTrace(Thread.java:2550) ~[?:?]
2023-02-24T11:13:38.616856595Z at io.temporal.internal.sync.ActivityStubBase.execute(ActivityStubBase.java:49) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616860595Z at io.temporal.internal.sync.ActivityInvocationHandler.lambda$getActivityFunc$0(ActivityInvocationHandler.java:78) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616864295Z at io.temporal.internal.sync.ActivityInvocationHandlerBase.invoke(ActivityInvocationHandlerBase.java:60) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616867695Z at jdk.proxy2.$Proxy88.runWithJobOutput(Unknown Source) ~[?:?]
2023-02-24T11:13:38.616872295Z at io.airbyte.workers.temporal.check.connection.CheckConnectionWorkflowImpl.run(CheckConnectionWorkflowImpl.java:51) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:38.616878895Z at CheckConnectionWorkflowImplProxy.run$accessor$uzZiizBT(Unknown Source) ~[?:?]
2023-02-24T11:13:38.616882595Z at CheckConnectionWorkflowImplProxy$auxiliary$nBiUxgJJ.call(Unknown Source) ~[?:?]
2023-02-24T11:13:38.616886495Z at io.airbyte.workers.temporal.support.TemporalActivityStubInterceptor.execute(TemporalActivityStubInterceptor.java:79) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:38.616890095Z at CheckConnectionWorkflowImplProxy.run(Unknown Source) ~[?:?]
2023-02-24T11:13:38.616893595Z at jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:104) ~[?:?]
2023-02-24T11:13:38.616897295Z at java.lang.reflect.Method.invoke(Method.java:578) ~[?:?]
2023-02-24T11:13:38.616915695Z at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation$RootWorkflowInboundCallsInterceptor.execute(POJOWorkflowImplementationFactory.java:302) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616919495Z at io.temporal.internal.sync.POJOWorkflowImplementationFactory$POJOWorkflowImplementation.execute(POJOWorkflowImplementationFactory.java:277) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616923595Z at io.temporal.internal.sync.WorkflowExecuteRunnable.run(WorkflowExecuteRunnable.java:71) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616927095Z at io.temporal.internal.sync.SyncWorkflow.lambda$start$0(SyncWorkflow.java:116) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616930295Z at io.temporal.internal.sync.CancellationScopeImpl.run(CancellationScopeImpl.java:102) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616933295Z at io.temporal.internal.sync.WorkflowThreadImpl$RunnableWrapper.run(WorkflowThreadImpl.java:106) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616936495Z at io.temporal.worker.ActiveThreadReportingExecutor.lambda$submit$0(ActiveThreadReportingExecutor.java:53) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:38.616939695Z at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577) ~[?:?]
2023-02-24T11:13:38.616943095Z at java.util.concurrent.FutureTask.run(FutureTask.java:317) ~[?:?]
2023-02-24T11:13:38.616946195Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
2023-02-24T11:13:38.616949295Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
2023-02-24T11:13:38.616953395Z at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2023-02-24T11:13:38.616956595Z Caused by: io.temporal.failure.TimeoutFailure: message='activity timeout', timeoutType=TIMEOUT_TYPE_SCHEDULE_TO_CLOSE
2023-02-24T11:13:48.660610954Z Log4j2Appender says: Running sync worker cancellation...
2023-02-24T11:13:48.660641454Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(lambda$getCancellationChecker$6):231 - Running sync worker cancellation...
2023-02-24T11:13:48.660663754Z Log4j2Appender says: Interrupting worker thread...
2023-02-24T11:13:48.660668154Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(lambda$getCancellationChecker$6):235 - Interrupting worker thread...
2023-02-24T11:13:48.660992253Z Log4j2Appender says: Cancelling completable future...
2023-02-24T11:13:48.661009053Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(lambda$getCancellationChecker$6):238 - Cancelling completable future...
2023-02-24T11:13:48.661177153Z Log4j2Appender says: Job either timed out or was cancelled.
2023-02-24T11:13:48.661193053Z 2023-02-24 11:13:48 e[33mWARNe[m i.a.c.t.CancellationHandler$TemporalCancellationHandler(checkAndHandleCancellation):53 - Job either timed out or was cancelled.
2023-02-24T11:13:48.661242653Z Log4j2Appender says: Unexpected error while checking connection:
2023-02-24T11:13:48.661308653Z 2023-02-24 11:13:48 e[1;31mERRORe[m i.a.w.g.DefaultCheckConnectionWorker(run):124 - Unexpected error while checking connection:
2023-02-24T11:13:48.661317352Z io.airbyte.workers.exception.WorkerException: null
2023-02-24T11:13:48.661321452Z at io.airbyte.workers.process.KubeProcessFactory.create(KubeProcessFactory.java:143) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661338652Z at io.airbyte.workers.process.AirbyteIntegrationLauncher.check(AirbyteIntegrationLauncher.java:100) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661342552Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:71) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661360152Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:41) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661363552Z at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:48.661366852Z at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2023-02-24T11:13:48.661370452Z Caused by: java.lang.InterruptedException
2023-02-24T11:13:48.661373852Z at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1681) ~[?:?]
2023-02-24T11:13:48.661377352Z at java.util.concurrent.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:515) ~[?:?]
2023-02-24T11:13:48.661380452Z at java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:677) ~[?:?]
2023-02-24T11:13:48.661383752Z at io.airbyte.workers.process.KubePortManagerSingleton.take(KubePortManagerSingleton.java:67) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661387152Z at io.airbyte.workers.process.KubeProcessFactory.create(KubeProcessFactory.java:101) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661390352Z ... 5 more
2023-02-24T11:13:48.661393552Z Log4j2Appender says: Stopping cancellation check scheduling...
2023-02-24T11:13:48.661407552Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(get):163 - Stopping cancellation check scheduling...
2023-02-24T11:13:48.661696351Z Log4j2Appender says: Activity failure. ActivityId=5c3a9cc7-9fb2-3c44-8838-e375ab84d03a, activityType=RunWithJobOutput, attempt=1
2023-02-24T11:13:48.661743951Z 2023-02-24 11:13:48 e[33mWARNe[m i.t.i.a.ActivityTaskExecutors$BaseActivityTaskExecutor(execute):114 - Activity failure. ActivityId=5c3a9cc7-9fb2-3c44-8838-e375ab84d03a, activityType=RunWithJobOutput, attempt=1
2023-02-24T11:13:48.661762651Z java.util.concurrent.CancellationException: null
2023-02-24T11:13:48.661766551Z at java.util.concurrent.CompletableFuture.cancel(CompletableFuture.java:2510) ~[?:?]
2023-02-24T11:13:48.661770251Z at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getCancellationChecker$6(TemporalAttemptExecution.java:241) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:48.661773751Z at io.airbyte.commons.temporal.CancellationHandler$TemporalCancellationHandler.checkAndHandleCancellation(CancellationHandler.java:52) ~[io.airbyte-airbyte-commons-temporal-0.40.32.jar:?]
2023-02-24T11:13:48.661776951Z at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getCancellationChecker$7(TemporalAttemptExecution.java:244) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:48.661780051Z at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:577) ~[?:?]
2023-02-24T11:13:48.661783451Z at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:358) ~[?:?]
2023-02-24T11:13:48.661786951Z at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
2023-02-24T11:13:48.661790151Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
2023-02-24T11:13:48.661793251Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
2023-02-24T11:13:48.661796851Z at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2023-02-24T11:13:48.661800051Z Log4j2Appender says: Completing future exceptionally...
2023-02-24T11:13:48.661807551Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.w.t.TemporalAttemptExecution(lambda$getWorkerThread$5):198 - Completing future exceptionally...
2023-02-24T11:13:48.661811151Z io.airbyte.workers.exception.WorkerException: Unexpected error while getting checking connection.
2023-02-24T11:13:48.661820451Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:126) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661823751Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:41) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661828051Z at io.airbyte.workers.temporal.TemporalAttemptExecution.lambda$getWorkerThread$5(TemporalAttemptExecution.java:195) ~[io.airbyte-airbyte-workers-0.40.32.jar:?]
2023-02-24T11:13:48.661831351Z at java.lang.Thread.run(Thread.java:1589) ~[?:?]
2023-02-24T11:13:48.661834851Z Caused by: io.airbyte.workers.exception.WorkerException
2023-02-24T11:13:48.661838051Z at io.airbyte.workers.process.KubeProcessFactory.create(KubeProcessFactory.java:143) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661841251Z at io.airbyte.workers.process.AirbyteIntegrationLauncher.check(AirbyteIntegrationLauncher.java:100) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661844351Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:71) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661848851Z ... 3 more
2023-02-24T11:13:48.661852051Z Caused by: java.lang.InterruptedException
2023-02-24T11:13:48.661855351Z at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1681) ~[?:?]
2023-02-24T11:13:48.661858551Z at java.util.concurrent.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:515) ~[?:?]
2023-02-24T11:13:48.661861751Z at java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:677) ~[?:?]
2023-02-24T11:13:48.661864951Z at io.airbyte.workers.process.KubePortManagerSingleton.take(KubePortManagerSingleton.java:67) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661868251Z at io.airbyte.workers.process.KubeProcessFactory.create(KubeProcessFactory.java:101) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661871251Z at io.airbyte.workers.process.AirbyteIntegrationLauncher.check(AirbyteIntegrationLauncher.java:100) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661874351Z at io.airbyte.workers.general.DefaultCheckConnectionWorker.run(DefaultCheckConnectionWorker.java:71) ~[io.airbyte-airbyte-commons-worker-0.40.32.jar:?]
2023-02-24T11:13:48.661877651Z ... 3 more
2023-02-24T11:13:48.661881151Z Log4j2Appender says:
2023-02-24T11:13:48.661887451Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2023-02-24T11:13:48.662012051Z Log4j2Appender says: ----- END CHECK -----
2023-02-24T11:13:48.662024551Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 - ----- END CHECK -----
2023-02-24T11:13:48.662155350Z Log4j2Appender says:
2023-02-24T11:13:48.662169950Z 2023-02-24 11:13:48 e[32mINFOe[m i.a.c.i.LineGobbler(voidCall):114 -
2023-02-24T11:13:48.663221647Z Log4j2Appender says: Failure during reporting of activity result to the server. ActivityId = 5c3a9cc7-9fb2-3c44-8838-e375ab84d03a, ActivityType = RunWithJobOutput, WorkflowId=038496e7-8574-44c0-b7cc-25d941f39670, WorkflowType=CheckConnectionWorkflow, RunId=03fde982-a8fd-4454-b270-9c45574cbbb8
2023-02-24T11:13:48.663254347Z 2023-02-24 11:13:48 e[33mWARNe[m i.t.i.w.ActivityWorker$TaskHandlerImpl(logExceptionDuringResultReporting):365 - Failure during reporting of activity result to the server. ActivityId = 5c3a9cc7-9fb2-3c44-8838-e375ab84d03a, ActivityType = RunWithJobOutput, WorkflowId=038496e7-8574-44c0-b7cc-25d941f39670, WorkflowType=CheckConnectionWorkflow, RunId=03fde982-a8fd-4454-b270-9c45574cbbb8
2023-02-24T11:13:48.663269147Z io.grpc.StatusRuntimeException: NOT_FOUND: workflow execution already completed
2023-02-24T11:13:48.663279347Z at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:271) ~[grpc-stub-1.51.1.jar:1.51.1]
2023-02-24T11:13:48.663283147Z at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:252) ~[grpc-stub-1.51.1.jar:1.51.1]
2023-02-24T11:13:48.663286347Z at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:165) ~[grpc-stub-1.51.1.jar:1.51.1]
2023-02-24T11:13:48.663290647Z at io.temporal.api.workflowservice.v1.WorkflowServiceGrpc$WorkflowServiceBlockingStub.respondActivityTaskFailed(WorkflowServiceGrpc.java:3866) ~[temporal-serviceclient-1.17.0.jar:?]
2023-02-24T11:13:48.663293947Z at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.lambda$sendReply$1(ActivityWorker.java:320) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663297247Z at io.temporal.internal.retryer.GrpcRetryer.lambda$retry$0(GrpcRetryer.java:52) ~[temporal-serviceclient-1.17.0.jar:?]
2023-02-24T11:13:48.663300447Z at io.temporal.internal.retryer.GrpcSyncRetryer.retry(GrpcSyncRetryer.java:67) ~[temporal-serviceclient-1.17.0.jar:?]
2023-02-24T11:13:48.663303647Z at io.temporal.internal.retryer.GrpcRetryer.retryWithResult(GrpcRetryer.java:60) ~[temporal-serviceclient-1.17.0.jar:?]
2023-02-24T11:13:48.663306747Z at io.temporal.internal.retryer.GrpcRetryer.retry(GrpcRetryer.java:50) ~[temporal-serviceclient-1.17.0.jar:?]
2023-02-24T11:13:48.663309847Z at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.sendReply(ActivityWorker.java:315) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663313247Z at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handleActivity(ActivityWorker.java:252) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663316647Z at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:206) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663319747Z at io.temporal.internal.worker.ActivityWorker$TaskHandlerImpl.handle(ActivityWorker.java:179) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663322947Z at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:93) ~[temporal-sdk-1.17.0.jar:?]
2023-02-24T11:13:48.663326247Z at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
2023-02-24T11:13:48.663329347Z at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
2023-02-24T11:13:48.663332647Z at java.lang.Thread.run(Thread.java:1589) ~[?:?]
Hello there! You are receiving this message because none of your fellow community members has stepped in to respond to your topic post. (If you are a community member and you are reading this response, feel free to jump in if you have the answer!) As a result, the Community Assistance Team has been made aware of this topic and will be investigating and responding as quickly as possible.
Some important considerations that will help your to get your issue solved faster:
It is best to use our topic creation template; if you haven’t yet, we recommend posting a followup with the requested information. With that information the team will be able to more quickly search for similar issues with connectors and the platform and troubleshoot more quickly your specific question or problem.
Make sure to upload the complete log file; a common investigation roadblock is that sometimes the error for the issue happens well before the problem is surfaced to the user, and so having the tail of the log is less useful than having the whole log to scan through.
Be as descriptive and specific as possible; when investigating it is extremely valuable to know what steps were taken to encounter the issue, what version of connector / platform / Java / Python / docker / k8s was used, etc. The more context supplied, the quicker the investigation can start on your topic and the faster we can drive towards an answer.
We in the Community Assistance Team are glad you’ve made yourself part of our community, and we’ll do our best to answer your questions and resolve the problems as quickly as possible. Expect to hear from a specific team member as soon as possible.
Thank you for your time and attention.
Best,
The Community Assistance Team