PreferredConstructor needs to improve bottleneck occurrence. [DATACMNS-1706]

[spring-projects-issues]

MyeongHyeonLee opened DATACMNS-1706 and commented

Bottleneck occurs when  there are many concurrent calls to "isConstructorParameter" in  "PreferredConstructor".

I have found that using Spring Data JDBC, the bottleneck occurs when there are many concurrent requests in "BasicJdbcConverter".

https://github.com/spring-projects/spring-data-jdbc/blob/c0803ddafef7a4bc4ec070df6581d46c4d59ff4a/spring-data-jdbc/src/main/java/org/springframework/data/jdbc/core/convert/BasicJdbcConverter.java#L400

 

It is expected to be improved by changing the lock of "PreferredConstructor#isConsturctorParameter" to  "ConcurrentHashMap".
It is expected to be improved by changing the lock of "PreferredConstructor # isConstructorParameter" to ConcurrentHashMap.
https://github.com/spring-projects/spring-data-commons/blob/master/src/main/java/org/springframework/data/mapping/PreferredConstructor.java#L134

---

Affects: 2.3 RC1 (Neumann)

Attachments:

• 스크린샷 2020-04-23 오전 3.02.05.png (148.66 kB)
• 스크린샷 2020-04-23 오전 3.12.42.png (57.69 kB)
• 스크린샷 2020-04-23 오후 2.26.35.png (115.79 kB)
• 스크린샷 2020-04-23 오후 2.27.27.png (229.37 kB)

Issue Links:

• DATAJDBC-546 Skip property population if entity can be constructed entirely using a full constructor

Referenced from: pull request #437

Backported to: 2.3.1 (Neumann SR1), 2.2.8 (Moore SR8)

[spring-projects-issues]

Mark Paluch commented

Thanks for report. Do you have any data to back up that read lock contention causes a performance impact? According to ReentrantReadWriteLock, read locks are shared and do not block any caller unless there is a write-thread

[spring-projects-issues]

MyeongHyeonLee commented

Mark Paluch

You're right.

If a new instance is deployed and concurrent request is received before warming up, WriteLock may occur and ReadLock can also be blocked.

ConcurrentHashMap does not block read even if write is being executed.

I think ReentrantReadWriteLock and ConcurrentHashMap don't make a big difference either.

If you think ReentrantReadWriteLock is enough, you can close the issue.

Thanks.

 

 

[spring-projects-issues]

Mark Paluch commented

Can you provide measurements/profiling data/benchmarks to back up the contention? Judging from the current perspective it's hard to go by gut feeling to introduce a change that can potentially incur several side-effects

[spring-projects-issues]

MyeongHyeonLee commented

Mark Paluch

I am not sure if ReentrantReadWriteLock is the problem.

I tried putting traffic in the API that runs Repository findAll().

There  are 100 data in the table.

 

@GetMapping("/test")
public List<Sample> test() {
    return this.sampleRepository.findAll();
}

 

 

A delay graph appears  and the CPU has reached 100%

 

• CPU 100%

!스크린샷 2020-04-23 오전 3.12.42.png|width=334,height=252!

 

• Delayed Latency

!스크린샷 2020-04-23 오전 3.02.05.png|width=351,height=195!

 

I extracted and analyzed ThreadDump using jstack, but couldn't find the exact cause yet.

I doubt that the ReentrantReadWriteLock of PreferredConstructor#isConstructorParameter may be CPU intensive.

A  lot of ReentrantReadWriteLock stacks were found in ThreadDump.

 

ReetrantReadWriteLock stack count 20 / Active Thread count 130 in ThreadDump

 

"http-nio-8080-exec-3" #44 daemon prio=5 os_prio=0 cpu=96499.48ms elapsed=1270.47s tid=0x00007f7d6b7f1800 nid=0x3f runnable  [0x00007f7ca5cf4000]
   java.lang.Thread.State: RUNNABLE
	at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryReleaseShared(java.base@11.0.6/ReentrantReadWriteLock.java:444)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.releaseShared(java.base@11.0.6/AbstractQueuedSynchronizer.java:1382)
	at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.unlock(java.base@11.0.6/ReentrantReadWriteLock.java:897)
	at org.springframework.data.mapping.PreferredConstructor.isConstructorParameter(PreferredConstructor.java:142)

—

"http-nio-8080-exec-7" #48 daemon prio=5 os_prio=0 cpu=96159.46ms elapsed=1270.47s tid=0x00007f7d6b7fa000 nid=0x43 runnable  [0x00007f7ca58f0000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ThreadLocal.get(java.base@11.0.6/ThreadLocal.java:163)
	at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryAcquireShared(java.base@11.0.6/ReentrantReadWriteLock.java:487)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.6/AbstractQueuedSynchronizer.java:1323)
	at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.6/ReentrantReadWriteLock.java:738)
	at org.springframework.data.mapping.PreferredConstructor.isConstructorParameter(PreferredConstructor.java:134)

—

"http-nio-8080-exec-23" #71 daemon prio=5 os_prio=0 cpu=85434.88ms elapsed=953.00s tid=0x00007f7c6001b800 nid=0x74 runnable  [0x00007f7c3b8f4000]
   java.lang.Thread.State: RUNNABLE
	at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.fullTryAcquireShared(java.base@11.0.6/ReentrantReadWriteLock.java:555)
	at java.util.concurrent.locks.ReentrantReadWriteLock$Sync.tryAcquireShared(java.base@11.0.6/ReentrantReadWriteLock.java:494)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireShared(java.base@11.0.6/AbstractQueuedSynchronizer.java:1323)
	at java.util.concurrent.locks.ReentrantReadWriteLock$ReadLock.lock(java.base@11.0.6/ReentrantReadWriteLock.java:738)
	at org.springframework.data.mapping.PreferredConstructor.isConstructorParameter(PreferredConstructor.java:134)


...

more..

 

There are RUNNABLE state (Not BLOCKED)

However, these stack can run many loops without blocking.

(Can occupy a lot of CPU.)

 

• ReentrantReadWriteLock$Sync.fullTryAcquireShared

    - https://github.com/openjdk-mirror/jdk7u-jdk/blob/master/src/share/classes/java/util/concurrent/locks/ReentrantReadWriteLock.java#L506

• ReentrantReadWriteLock$Sync.tryReleaseShared

    - https://github.com/openjdk-mirror/jdk7u-jdk/blob/master/src/share/classes/java/util/concurrent/locks/ReentrantReadWriteLock.java#L435  

   

I'm not sure if it's a ReentrantReadWriteLock problem, but I doubt it.

 

 

[spring-projects-issues]

MyeongHyeonLee commented

I tried running the profiler to find targets that are heavily using cpu.

!스크린샷 2020-04-23 오후 2.26.35.png|width=468,height=274!

 

ReadLock.lock takes a large part.

 

!스크린샷 2020-04-23 오후 2.27.27.png|width=394,height=474!

 

Among them, acquireShared / tryAcquireShared is main worker.

 

 

[spring-projects-issues]

MyeongHyeonLee commented

Mark Paluch 

A benchmark test was conducted on three implementation methods.

mhyeon-lee#1

 

Using ConcurrentHashMap and using put / get gives the best results.

 

Benchmark                                                                                    Mode  Cnt    Score    Error  Units
PreferredConstructorPerformanceTests.isConstructorParameterConcurrentHashMap                 avgt    5    5.228 ±  0.151  ms/op
PreferredConstructorPerformanceTests.isConstructorParameterConcurrentHashMapComputeIfAbsent  avgt    5   99.477 ±  3.389  ms/op
PreferredConstructorPerformanceTests.isConstructorParameterReadLock                          avgt    5  754.467 ± 45.543  ms/op

 

 

You can also test it by changing the desired conditions.

 

Please review

[spring-projects-issues]

Mark Paluch commented

Thanks for your contribution. That's merged now

[spring-projects-issues]

MyeongHyeonLee commented

Mark Paluch

After upgrading to Spring Data Commons 2.3.1, Spring Data JDBC 2.0.1

I share the performance test results.

 

• Kubernetes, 1 POD, CPU 4 Core, SELECT Query API Per 120 Row ResultSet

 

• Spring Data Commons 2.3.0 , Spring Data JDBC 2.0.0
  • TPS 230 
  • y-axis (5,000 ms)
  • CPU Usage 100%

!image-2020-06-15-11-30-45-521.png!

 

• Spring Data Commons 2.3.1, Spring Data JDBC 2.0.1

  • TPS 230
  • y-axis (3,000 ms)
  • CPU Usage 20%

• !image-2020-06-15-11-31-14-787.png|width=364,height=230!

• TPS 750

• y-axis (10,000 ms)

• CPU Usage 100%

• !image-2020-06-15-11-39-59-674.png|width=368,height=250!  

 

It is now possible to process TPS 3 times based on the test API.

Thank you very much.