Pipeline runner non retryable state CompletedStepStateModel

[David Bergevoet]

Hello dear stranger,

I have a problem with one of my runners which caused it to be in a non retryable state, whenever it starts. The logs says 'step was already complete skipping'. The complete log can be found below.
After this happens, the runner wont start a new step, even tho it says it will. 

I hope you will have a clue of what is going on. If necessary I will give the information you need. Thank you anyway for reading this!

[2022-06-07 06:09:37,448] Runner version: 1.323
[2022-06-07 06:09:37,468] Runner runtime: linux-docker
[2022-06-07 06:09:38,953] Copying Docker cli to working directory.
[2022-06-07 06:09:39,243] Starting websocket listening to RUNNER_UPDATED events.
[2022-06-07 06:09:39,344] Updating runner status to "ONLINE" and checking for new steps assigned to the runner after 0 seconds and then every 30 seconds.
[2022-06-07 06:09:39,576] Updating runner state to "ONLINE".
[2022-06-07 06:09:40,611] Setting runner state to executing step.
[2022-06-07 06:09:40,633] Getting step StepId{accountUuid={[id]}, repositoryUuid={[id]}, pipelineUuid={[id]}, stepUuid={[id]}}.
[2022-06-07 06:09:40,647] Getting oauth token for step.
[2022-06-07 06:09:40,654] Getting environment variables for step.
[2022-06-07 06:09:41,182] Getting all artifacts for step.
[2022-06-07 06:09:41,187] Getting SSH private key.
[2022-06-07 06:09:41,191] Getting known hosts.
[2022-06-07 06:09:41,414] SSH private key not found
[2022-06-07 06:09:41,426] Runner is in a non retryable state. (state: CompletedStepStateModel{result=StoppedResultForCompletedStepStateModel{}})
[2022-06-07 06:09:41,429] Step was already complete skipping.
[2022-06-07 06:09:41,435] Completing step with result Result{status=ERROR, error=Some(Error{key='runner.step.execution-error', message='null', arguments={}})}.
[2022-06-07 06:09:41,657] An error occurred whilst completing step.
com.atlassian.pipelines.stargate.client.core.exceptions.StargateBadRequestException: Response Summary: HttpResponseSummary{httpStatusCode=400, httpStatusMessage=Bad Request, bodyAsString={"error":{"message":"Bad request","detail":"Attempt to complete an already completed step (existing status=STOPPED, new status=ERROR, existing error=null, new error=runner.step.execution-error)","data":{"key":"result-service.step.invalid-state","arguments":{}}}}}
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException:
Error has been observed at the following site(s):
*__checkpoint ⇢ 400 from POST https://api.atlassian.com/ex/bitbucket-pipelines/rest/1.0/accounts/%7B[id]%7D/repositories/%7B[id]%7D/pipelines/%7B[id]%7D/steps/%7B[id]%7D/stepComplete [DefaultWebClient]
Original Stack Trace:
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.base/java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.atlassian.bitbucketci.client.reactive.ResponseExceptionFactory$ConstructorInvoker.invokeConstructor(ResponseExceptionFactory.java:117)
at io.vavr.CheckedFunction1.lambda$unchecked$43b513dd$1(CheckedFunction1.java:220)
at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:106)
at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:120)
at reactor.core.publisher.FluxDefaultIfEmpty$DefaultIfEmptySubscriber.onNext(FluxDefaultIfEmpty.java:101)
at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:127)
at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onNext(FluxContextWrite.java:107)
at reactor.core.publisher.FluxMapFuseable$MapFuseableConditionalSubscriber.onNext(FluxMapFuseable.java:295)
at reactor.core.publisher.FluxFilterFuseable$FilterFuseableConditionalSubscriber.onNext(FluxFilterFuseable.java:337)
at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1816)
at reactor.core.publisher.MonoCollect$CollectSubscriber.onComplete(MonoCollect.java:159)
at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:142)
at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:260)
at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:142)
at reactor.netty.channel.FluxReceive.onInboundComplete(FluxReceive.java:400)
at reactor.netty.channel.ChannelOperations.onInboundComplete(ChannelOperations.java:419)
at reactor.netty.channel.ChannelOperations.terminate(ChannelOperations.java:473)
at reactor.netty.http.client.HttpClientOperations.onInboundNext(HttpClientOperations.java:703)
at reactor.netty.channel.ChannelOperationsHandler.channelRead(ChannelOperationsHandler.java:93)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299)
at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1372)
at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1235)
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1284)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:510)
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:449)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:279)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:800)
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:480)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:378)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Unknown Source)
[2022-06-07 06:09:41,662] Setting runner state to not executing step.
[2022-06-07 06:09:41,662] Waiting for next step.

[David Bergevoet · Accepted solution]

https://community.atlassian.com/t5/Bitbucket-Pipelines-Runners/Runner-is-stuck-on-a-step-quot-runner-in-a-non-retryable-state/m-p/1674764#M14