search

micronaut-projects / micronaut-serialization

Build Time Serialization APIs for Micronaut
Apache License 2.0
26 stars 19 forks source link

Deadlock in SerBean.initialize() - SerBean.java:308 #842

Closed cdandoy closed 3 months ago

cdandoy commented 4 months ago

Expected Behavior

No deadlock expected.

Actual Behaviour

Deadlock encountered.

Steps To Reproduce

I have a React front end that issues several requests in parallel to a Micronaut backend to populate the UI. I am not sure yet what triggered the issue, but I suddenly have all my requests pending in Chrome. I captured a stack trace and found out it was caused by a deadlock in SerBean.initialize(). Based on the stacks and on my knowledge of the code, I suspect the issue is caused by inter-dependent data structures (records). Here is a simplified representation of what might be the cause:

    record Application(String applicationName, Database database){}
    record Database(String databaseName, List<Application> applications){}

    @Get("/application/{appId}")
    Application getApplication(@PathVariable long appId) {
        return null;
    }

    @Get("/database/{dbId}")
    Database getDatabase(@PathVariable long dbId) {
        return null;
    }

I haven't been able to reproduce this in a simplified test application yet but will give it a try.

First thread

"io-executor-thread-5@13748" prio=5 tid=0x32 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     blocks io-executor-thread-1@12531
     waiting for io-executor-thread-1@12531 to release lock on <0x36a4> (a io.micronaut.serde.support.serializers.SerBean)
      at io.micronaut.serde.support.serializers.SerBean.initialize(SerBean.java:308)
      at io.micronaut.serde.support.serializers.ObjectSerializer.getSerializableBean(ObjectSerializer.java:121)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecificInternal(ObjectSerializer.java:84)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:76)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:52)
      at io.micronaut.serde.support.serializers.SerBean.initProperty(SerBean.java:338)
      at io.micronaut.serde.support.serializers.SerBean.lambda$new$12(SerBean.java:243)
      at io.micronaut.serde.support.serializers.SerBean$$Lambda$1623/0x000001bf8a14f040.initialize(Unknown Source:-1)
      at io.micronaut.serde.support.serializers.SerBean.initialize(SerBean.java:311)
      - locked <0x36a5> (a io.micronaut.serde.support.serializers.SerBean)
      at io.micronaut.serde.support.serializers.ObjectSerializer.getSerializableBean(ObjectSerializer.java:121)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecificInternal(ObjectSerializer.java:84)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:76)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:52)
      at io.micronaut.serde.support.serializers.IterableSerializer.createSpecific(IterableSerializer.java:40)
      at io.micronaut.serde.support.serializers.SerBean.initProperty(SerBean.java:338)
      at io.micronaut.serde.support.serializers.SerBean.lambda$new$12(SerBean.java:243)
      at io.micronaut.serde.support.serializers.SerBean$$Lambda$1623/0x000001bf8a14f040.initialize(Unknown Source:-1)
      at io.micronaut.serde.support.serializers.SerBean.initialize(SerBean.java:311)
      - locked <0x36b6> (a io.micronaut.serde.support.serializers.SerBean)
      at io.micronaut.serde.support.serializers.ObjectSerializer.getSerializableBean(ObjectSerializer.java:121)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecificInternal(ObjectSerializer.java:84)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:76)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:52)
      at io.micronaut.serde.support.serializers.IterableSerializer.createSpecific(IterableSerializer.java:40)
      at io.micronaut.serde.jackson.JacksonJsonMapper.writeValue(JacksonJsonMapper.java:159)
      at io.micronaut.serde.jackson.JacksonJsonMapper.writeValue(JacksonJsonMapper.java:240)
      at io.micronaut.json.body.JsonMessageHandler.writeTo(JsonMessageHandler.java:138)
      at io.micronaut.http.body.MessageBodyWriter.writeTo(MessageBodyWriter.java:138)
      at io.micronaut.http.netty.body.NettyJsonHandler.writeTo(NettyJsonHandler.java:137)
      at io.micronaut.http.server.netty.RoutingInBoundHandler$CompatNettyWriteClosure.writeTo(RoutingInBoundHandler.java:527)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.writeNettyMessageBody(RoutingInBoundHandler.java:359)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.encodeHttpResponse(RoutingInBoundHandler.java:338)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.writeResponse(RoutingInBoundHandler.java:233)
      at io.micronaut.http.server.netty.NettyRequestLifecycle.lambda$handleNormal$0(NettyRequestLifecycle.java:87)
      at io.micronaut.http.server.netty.NettyRequestLifecycle$$Lambda$1419/0x000001bf8a012828.accept(Unknown Source:-1)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$1.onComplete(ReactorExecutionFlowImpl.java:121)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:549)
      at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:159)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:245)
      at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:250)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.Operators$MonoInnerProducerBase.complete(Operators.java:2781)
      at reactor.core.publisher.SinkOneMulticast.tryEmitValue(SinkOneMulticast.java:67)
      at reactor.core.publisher.SinkOneSerialized.tryEmitValue(SinkOneSerialized.java:38)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$2.accept(ReactorExecutionFlowImpl.java:171)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$2.accept(ReactorExecutionFlowImpl.java:164)
      at io.micronaut.core.execution.ImperativeExecutionFlowImpl.onComplete(ImperativeExecutionFlowImpl.java:132)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl$OnComplete.apply(DelayedExecutionFlowImpl.java:330)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.work(DelayedExecutionFlowImpl.java:51)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.complete0(DelayedExecutionFlowImpl.java:64)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.complete(DelayedExecutionFlowImpl.java:70)
      at io.micronaut.core.execution.ExecutionFlow.lambda$async$0(ExecutionFlow.java:94)
      at io.micronaut.core.execution.ExecutionFlow$$Lambda$1421/0x000001bf8a012c98.accept(Unknown Source:-1)
      at io.micronaut.core.execution.ImperativeExecutionFlowImpl.onComplete(ImperativeExecutionFlowImpl.java:132)
      at io.micronaut.core.execution.ExecutionFlow.lambda$async$1(ExecutionFlow.java:87)
      at io.micronaut.core.execution.ExecutionFlow$$Lambda$1186/0x000001bf89fcbc40.run(Unknown Source:-1)
      at io.micronaut.core.propagation.PropagatedContext.lambda$wrap$3(PropagatedContext.java:211)
      at io.micronaut.core.propagation.PropagatedContext$$Lambda$1479/0x000001bf8a052c80.run(Unknown Source:-1)
      at io.micronaut.core.propagation.PropagatedContext.lambda$wrap$3(PropagatedContext.java:211)
      at io.micronaut.core.propagation.PropagatedContext$$Lambda$1479/0x000001bf8a052c80.run(Unknown Source:-1)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
      at java.lang.Thread.run(Thread.java:840)

Second thread

"io-executor-thread-1@12531" prio=5 tid=0x27 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
     blocks io-executor-thread-2@13382
     blocks io-executor-thread-5@13748
     waiting for io-executor-thread-5@13748 to release lock on <0x36a5> (a io.micronaut.serde.support.serializers.SerBean)
      at io.micronaut.serde.support.serializers.SerBean.initialize(SerBean.java:308)
      at io.micronaut.serde.support.serializers.ObjectSerializer.getSerializableBean(ObjectSerializer.java:121)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecificInternal(ObjectSerializer.java:84)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:76)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:52)
      at io.micronaut.serde.support.serializers.IterableSerializer.createSpecific(IterableSerializer.java:40)
      at io.micronaut.serde.support.serializers.SerBean.initProperty(SerBean.java:338)
      at io.micronaut.serde.support.serializers.SerBean.lambda$new$12(SerBean.java:243)
      at io.micronaut.serde.support.serializers.SerBean$$Lambda$1623/0x000001bf8a14f040.initialize(Unknown Source:-1)
      at io.micronaut.serde.support.serializers.SerBean.initialize(SerBean.java:311)
      - locked <0x36a4> (a io.micronaut.serde.support.serializers.SerBean)
      at io.micronaut.serde.support.serializers.ObjectSerializer.getSerializableBean(ObjectSerializer.java:121)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecificInternal(ObjectSerializer.java:84)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:76)
      at io.micronaut.serde.support.serializers.ObjectSerializer.createSpecific(ObjectSerializer.java:52)
      at io.micronaut.serde.support.serializers.IterableSerializer.createSpecific(IterableSerializer.java:40)
      at io.micronaut.serde.jackson.JacksonJsonMapper.writeValue(JacksonJsonMapper.java:159)
      at io.micronaut.serde.jackson.JacksonJsonMapper.writeValue(JacksonJsonMapper.java:240)
      at io.micronaut.json.body.JsonMessageHandler.writeTo(JsonMessageHandler.java:138)
      at io.micronaut.http.body.MessageBodyWriter.writeTo(MessageBodyWriter.java:138)
      at io.micronaut.http.netty.body.NettyJsonHandler.writeTo(NettyJsonHandler.java:137)
      at io.micronaut.http.server.netty.RoutingInBoundHandler$CompatNettyWriteClosure.writeTo(RoutingInBoundHandler.java:527)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.writeNettyMessageBody(RoutingInBoundHandler.java:359)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.encodeHttpResponse(RoutingInBoundHandler.java:338)
      at io.micronaut.http.server.netty.RoutingInBoundHandler.writeResponse(RoutingInBoundHandler.java:233)
      at io.micronaut.http.server.netty.NettyRequestLifecycle.lambda$handleNormal$0(NettyRequestLifecycle.java:87)
      at io.micronaut.http.server.netty.NettyRequestLifecycle$$Lambda$1419/0x000001bf8a012828.accept(Unknown Source:-1)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$1.onComplete(ReactorExecutionFlowImpl.java:121)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onComplete(FluxOnAssembly.java:549)
      at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:159)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:245)
      at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:250)
      at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onNext(FluxOnAssembly.java:539)
      at reactor.core.publisher.Operators$MonoInnerProducerBase.complete(Operators.java:2781)
      at reactor.core.publisher.SinkOneMulticast.tryEmitValue(SinkOneMulticast.java:67)
      at reactor.core.publisher.SinkOneSerialized.tryEmitValue(SinkOneSerialized.java:38)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$2.accept(ReactorExecutionFlowImpl.java:171)
      at io.micronaut.http.reactive.execution.ReactorExecutionFlowImpl$2.accept(ReactorExecutionFlowImpl.java:164)
      at io.micronaut.core.execution.ImperativeExecutionFlowImpl.onComplete(ImperativeExecutionFlowImpl.java:132)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl$OnComplete.apply(DelayedExecutionFlowImpl.java:330)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.work(DelayedExecutionFlowImpl.java:51)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.complete0(DelayedExecutionFlowImpl.java:64)
      at io.micronaut.core.execution.DelayedExecutionFlowImpl.complete(DelayedExecutionFlowImpl.java:70)
      at io.micronaut.core.execution.ExecutionFlow.lambda$async$0(ExecutionFlow.java:94)
      at io.micronaut.core.execution.ExecutionFlow$$Lambda$1421/0x000001bf8a012c98.accept(Unknown Source:-1)
      at io.micronaut.core.execution.ImperativeExecutionFlowImpl.onComplete(ImperativeExecutionFlowImpl.java:132)
      at io.micronaut.core.execution.ExecutionFlow.lambda$async$1(ExecutionFlow.java:87)
      at io.micronaut.core.execution.ExecutionFlow$$Lambda$1186/0x000001bf89fcbc40.run(Unknown Source:-1)
      at io.micronaut.core.propagation.PropagatedContext.lambda$wrap$3(PropagatedContext.java:211)
      at io.micronaut.core.propagation.PropagatedContext$$Lambda$1479/0x000001bf8a052c80.run(Unknown Source:-1)
      at io.micronaut.core.propagation.PropagatedContext.lambda$wrap$3(PropagatedContext.java:211)
      at io.micronaut.core.propagation.PropagatedContext$$Lambda$1479/0x000001bf8a052c80.run(Unknown Source:-1)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
      at java.lang.Thread.run(Thread.java:840)

Environment Information

Example Application

No response

Version

4.2.0