Skip to content

spring lettuce startup get blocks when including spring-cloud-starter-zipkin  #1557

New issue
New issue
Closed
Closed
spring lettuce startup get blocks when including spring-cloud-starter-zipkin #1557
Labels
enhancement
Milestone
 
3.0.0-M4
@WEIZIBIN

Description

@WEIZIBIN
WEIZIBIN
opened on Feb 12, 2020

Describe the bug
Spring redis get connection block when include spring-cloud-starter-zipkin.

2020-02-12 11:31:27.025 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.sleuth.zipkin2.sender.ZipkinRestTemplateSenderConfiguration' of type [org.springframework.cloud.sleuth.zipkin2.sender.ZipkinRestTemplateSenderConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.027 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'zipkinRestTemplateCustomizer' of type [org.springframework.cloud.sleuth.zipkin2.DefaultZipkinRestTemplateCustomizer] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.038 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'zipkinSender' of type [org.springframework.cloud.sleuth.zipkin2.sender.RestTemplateSender] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.075 WARN [,,,] 25158 --- [ main] o.s.c.s.zipkin2.ZipkinAutoConfiguration : Check result of the [AsyncReporter{org.springframework.cloud.sleuth.zipkin2.sender.RestTemplateSender@1dba4e06}] contains an error [CheckResult{ok=false, error=org.springframework.web.client.ResourceAccessException: I/O error on POST request for "http://localhost:9411/api/v2/spans": Connection refused (Connection refused); nested exception is java.net.ConnectException: Connection refused (Connection refused)}]
2020-02-12 11:31:27.076 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'zipkinReporter' of type [zipkin2.reporter.AsyncReporter$BoundedAsyncReporter] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.086 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'tracing' of type [brave.Tracing$Default] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.089 INFO [,,,] 25158 --- [ main] trationDelegate$BeanPostProcessorChecker : Bean 'spring.sleuth.redis-org.springframework.cloud.sleuth.instrument.redis.TraceRedisProperties' of type [org.springframework.cloud.sleuth.instrument.redis.TraceRedisProperties] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2020-02-12 11:31:27.454 INFO [,,,] 25158 --- [ main] io.lettuce.core.EpollProvider : Starting without optional epoll library
2020-02-12 11:31:27.455 INFO [,,,] 25158 --- [ main] io.lettuce.core.KqueueProvider : Starting without optional kqueue library

If pom.xml not include spring-cloud-starter-zipkin, then redis success get connection.

Sample
Sample Project
block in io.lettuce.core.AbstractRedisClient#getConnection()

Activity

spring-projects-issues
added
waiting-for-triage
on Feb 12, 2020
marcingrzejszczak

marcingrzejszczak commented on Feb 12, 2020

@marcingrzejszczak
marcingrzejszczak
on Feb 12, 2020
Contributor

@mp911de have you seen such a problem before?

marcingrzejszczak
added
waiting for feedback
and removed
waiting-for-triage
on Feb 12, 2020
mp911de

mp911de commented on Feb 12, 2020

@mp911de
mp911de
on Feb 12, 2020
Member

Do you mean Connection refused (Connection refused); nested exception is java.net.ConnectException: Connection refused (Connection refused)}] or the bean-postprocesors?

spring-projects-issues
added
feedback-provided
and removed
waiting for feedback
on Feb 12, 2020
marcingrzejszczak

marcingrzejszczak commented on Feb 12, 2020

@marcingrzejszczak
marcingrzejszczak
on Feb 12, 2020
Contributor

From what I understand this the problem block in io.lettuce.core.AbstractRedisClient#getConnection() . All the entries in the logs are not related to the issue as far as I understand.

BTW @WEIZIBIN you know that we have Hoxton.SR1 ?

mp911de

mp911de commented on Feb 12, 2020

@mp911de
mp911de
on Feb 12, 2020
Member

The application startup gets stuck (blocked). There are two things that come together:

  1. Calling Redis in @PostConstruct which awaits command completion since it's a blocking call.
  2. Background initialization of Brave in combination with AOP. The I/O thread gets blocked by Brave/AOP by the Spring Framework initialization lock.

Since the context is not fully started, the startup lock prevents progress each time a thread different than main tries to obtain a Spring bean. Here's the stack trace of the blocked thread:

"lettuce-nioEventLoop-4-1@6556" daemon prio=5 tid=0x26 nid=NA waiting for monitor entry
  java.lang.Thread.State: BLOCKED
	 waiting for main@1 to release lock on <0x1c0c> (a java.util.concurrent.ConcurrentHashMap)
	  at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:205)
	  at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:321)
	  at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
	  at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:409)
	  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1338)
	  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1177)
	  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:557)
	  at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:517)
	  at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$1(AbstractBeanFactory.java:359)
	  at org.springframework.beans.factory.support.AbstractBeanFactory$$Lambda$523.791402620.getObject(Unknown Source:-1)
	  at org.springframework.cloud.context.scope.GenericScope$BeanLifecycleWrapper.getBean(GenericScope.java:389)
	  - locked <0x1c45> (a java.lang.String)
	  at org.springframework.cloud.context.scope.GenericScope.get(GenericScope.java:186)
	  at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:356)
	  at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:202)
	  at org.springframework.aop.target.SimpleBeanTargetSource.getTarget(SimpleBeanTargetSource.java:35)
	  at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673)
	  at brave.sampler.Sampler$$EnhancerBySpringCGLIB$$79d02789.isSampled(<generated>:-1)
	  at brave.Tracer.decorateContext(Tracer.java:268)
	  at brave.Tracer.newRootContext(Tracer.java:204)
	  at brave.Tracer.newTrace(Tracer.java:151)
	  at brave.Tracer.nextSpan(Tracer.java:470)
	  at io.lettuce.core.tracing.BraveTracing$BraveTracer.nextSpan(BraveTracing.java:259)
	  at io.lettuce.core.tracing.BraveTracing$BraveTracer.nextSpan(BraveTracing.java:266)
	  at io.lettuce.core.protocol.CommandHandler.writeSingleCommand(CommandHandler.java:392)
	  at io.lettuce.core.protocol.CommandHandler.write(CommandHandler.java:353)
	  at io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:716)
	  at io.netty.channel.AbstractChannelHandlerContext.invokeWrite(AbstractChannelHandlerContext.java:708)
	  at io.netty.channel.AbstractChannelHandlerContext.access$1700(AbstractChannelHandlerContext.java:56)
	  at io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.write(AbstractChannelHandlerContext.java:1102)
	  at io.netty.channel.AbstractChannelHandlerContext$WriteAndFlushTask.write(AbstractChannelHandlerContext.java:1149)
	  at io.netty.channel.AbstractChannelHandlerContext$AbstractWriteTask.run(AbstractChannelHandlerContext.java:1073)
	  at io.netty.util.concurrent.AbstractEventExecutor.safeExecute$$$capture(AbstractEventExecutor.java:163)
	  at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:-1)
	  at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510)
	  at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518)
	  at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050)
	  at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	  at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	  at java.lang.Thread.run(Thread.java:830)
mp911de
mentioned this on Feb 12, 2020
WEIZIBIN

WEIZIBIN commented on Feb 12, 2020

@WEIZIBIN
WEIZIBIN
on Feb 12, 2020
Author

Thanks, I have reached the same conclusion after using the jstack command. Has this issue been resolved now? @mp911de

WEIZIBIN

WEIZIBIN commented on Feb 12, 2020

@WEIZIBIN
WEIZIBIN
on Feb 12, 2020
Author

I upgraded to Hoxton.SR1 and still have the same problem. @marcingrzejszczak

Comven

Comven commented on Feb 12, 2020

@Comven
Comven
on Feb 12, 2020

I upgraded to Hoxton.SR1 and still have the same problem. @marcingrzejszczak

spring-boot-2.2.4+spring-cloud Hoxton.SR1 have the same problem

WEIZIBIN

WEIZIBIN commented on Feb 12, 2020

@WEIZIBIN
WEIZIBIN
on Feb 12, 2020
Author

My current solution is to execute it before redis executes the command.
tracing.tracer().nextSpan ();
Then [Main] thread initializes Tracer first, so when redis executes the command, the IO thread will not block at getSingleton().

Is there a better solution?

WEIZIBIN
changed the title [-]spring redis get connection block when include spring-cloud-starter-zipkin [/-] [+]spring lettuce startup get blocks when including spring-cloud-starter-zipkin [/+] on Feb 12, 2020

21 remaining items

Loading
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    enhancement

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

      Development

      No branches or pull requests

        Participants

        @elvizlai@spencergibb@mp911de@marcingrzejszczak@Comven

        Issue actions
          spring lettuce startup get blocks when including spring-cloud-starter-zipkin · Issue #1557 · spring-cloud/spring-cloud-sleuth