Jente Sondervorst
Jente Sondervorst

Reputation: 58

JdkDynamicAopProxy takes over 1 minute to start invoke method when proxy of a @Repository annotated bean

The problem

I'm experiencing a very strange problem when calling the save method on my constructor injected repository bean. I've narrowed down the problem to the JdkDynamicAopProxy which is the first called method visible in intelliJ's frame overview. I put a breakpoint on the first line in invoke method. It takes over a minute to get from the call to the breakpoint. Nothing (visibly) is happening in between these two frames.

The code

Controller

    @Controller
    class LoginController(private val userRepository: UserRepository, val passwordEncoder: PasswordEncoder) {

        @PostMapping(value = ["/register"])
        fun register(@RequestParam("mail") mail: String?, @RequestParam("password") pass: String?, model: Model) : ModelAndView
        {
            val modelAndView = ModelAndView("index")
            if (mail == null || mail == "" || pass == null || pass == "") {
                modelAndView.status = HttpStatus.NOT_ACCEPTABLE;
                return modelAndView
            }
            // IT IS THE NEXT LINE WHICH IS CAUSING THE LONG WAIT...
            userRepository.save(User(email = mail, password = passwordEncoder.encode(pass), newPassword = pass, firstname = "Test", lastname = "Persoon"))
            modelAndView.status = HttpStatus.OK
            return modelAndView

        }
    }

User repository

    @Repository
    interface UserRepository : JpaRepository<User, Long> {
        fun findByEmail(email: String): User
    }

application.properties

    spring.datasource.url=jdbc:mysql://localhost:3306/db?serverTimezone=GMT%2B1&useSSL=FALSE&allowPublicKeyRetrieval=true
    spring.datasource.username=username
    spring.datasource.password=password
    spring.datasource.hikari.connectionTimeout=20000
    spring.datasource.hikari.maximumPoolSize=5
    spring.datasource.hikari.poolName=Connections

    spring.jpa.hibernate.ddl-auto=update
    spring.jpa.show-sql=true
    spring.jpa.database=mysql
    spring.jpa.database-platform=org.hibernate.dialect.MySQL5InnoDBDialect

    spring.thymeleaf.suffix=.xhtml

    logging.level.org.springframework=INFO
    logging.level.com.zaxxer=ERROR
    logging.level.com.jenson=INFO
    logging.level.root=ERROR
    logging.level.org.hibernate.type=TRACE

The frames

From the register:33, loginController To the invoke:157, JdkDynamicAopProxy It is taking over 1 minute.

I do not seem to be able to enter that one "frame" in between..

Overview of the last frames during execution

EDIT: THE SOLUTION IN THE END

Not the call, but the password encoding was the issue.

The problem was in the BCryptEncoder bean.

    fun bCryptEncoder() : PasswordEncoder = BCryptPasswordEncoder(20)

Checking in the source code of the BCryptEncoder tells me that 10 is the empty constructor strength. Using empty constructor and method only takes less than a second now.

Upvotes: 0

Views: 452

Answers (1)

C-Shark
C-Shark

Reputation: 821

I see a passwordEncoder.encode(pass) on that "slow line". That's why i think this can be the classic "/dev/urandom" problem.

https://ruleoftech.com/2016/avoiding-jvm-delays-caused-by-random-number-generation

If you are running this code from an IDE, make sure that the actual JVM (that runs your program, not your IDE) has this configuration.

Upvotes: 2

Related Questions