55

I'm using HikariCP 2.4.6 and at Tomcat 8 startup, I get a warning message:

01-Aug-2016 11:18:01.599 INFO [RMI TCP Connection(4)-127.0.0.1] org.apache.catalina.core.ApplicationContext.log Initializing Spring FrameworkServlet 'Spring MVC Dispatcher Servlet'
[2016-08-01 11:18:01,654] Artifact blueberry:war exploded: Artifact is deployed successfully
[2016-08-01 11:18:01,655] Artifact blueberry:war exploded: Deploy took 33,985 milliseconds
Aug 01 2016 11:26:52.802 AM [DEV] (HikariPool.java:614)
WARN : com.zaxxer.hikari.pool.HikariPool - 9m13s102ms - Thread starvation or clock leap detected (housekeeper delta=springHikariConnectionPool).

I don't see any other errors or issues reading/writing from the DB. Is this something to be concerned about? I tried searching around, but no luck.

We're also using Hibernate 4.3.8.Final over MySQL 5 and the MySQL 5.1.39 connector with Spring 4.1.0.RELEASE. We're working to upgrade to Hibernate 5 and will see whether this goes away, but don't know whether that will matter.

vphilipnyc
  • 6,607
  • 6
  • 44
  • 70

6 Answers6

60

There's a good rundown of why clock leap detections might legitimately occur. To quote the external link by Brett Woolridge:

This runs on the housekeeper thread, which executes every 30 seconds. If you are on Mac OS X, the clockSource is System.currentTimeMillis(), any other platform the clockSource is System.nanoTime(). Both in theory are monotonically increasing, but various things can affect that such as NTP servers. Most OSes are designed to handle backward NTP time adjustments to preserve the illusion of the forward flow of time.

This code is saying, if time moves backwards (now < previous), or if time has "jumped forward" more than two housekeeping periods (more than 60 seconds), then something strange is likely going on.

A couple of things might be going on:

  1. You could be running in a virtual container (VMWare, AWS, etc.) that for some reason is doing a particularly poor job of maintaining the illusion of the forward flow of time.

  2. Because other things occur in the housekeeper thread -- specifically, closing idle connections -- it is possible that for some reason closing connections is blocking the housekeeper thread for more than two housekeeping periods (60 seconds).

  3. The server is so busy, with all CPUs pegged, that thread starvation is occurring, which is preventing the housekeeper thread from running for more than two housekeeping periods.

Considering these, maybe you can provide additional context.

EDIT: Note that this is based on HikariCP 2.4.1 code. Make sure you are running the most up-to-date version available.

(It also looks like the parameters were updated on the warning statement in the latest code.)

vphilipnyc
  • 6,607
  • 6
  • 44
  • 70
  • 61
    Reason 3 is also occuring when you are debugging your application and are waiting longer than two housekeeping periods (60 seconds) at one breakpoint. After continuing the progress, Hikari is complaining with warnings like in the question above. – GreenTurtle May 11 '17 at 10:56
32

One other reason if you run the app locally and the computer went to sleep it happens. In that case, you don't need to do anything configure wise.

vphilipnyc
  • 6,607
  • 6
  • 44
  • 70
ikarayel
  • 2,214
  • 16
  • 22
3

I was having the same issue when I ran my spring boot application with microservices on the Linux machine. After some investigation found out that, the server has only 8GB memory. Increasing Memory(RAM) to 16GB fixed my issue.

flashleo
  • 33
  • 6
2

I was facing this issue in a spring boot MySQL work in an AWS T2 micro 1GB RAM instance . After an hours effort and nothing moving forward , observed that CPU usage was going towards 100% . Then I made the instance T2 medium having 4 GB RAM and 2 vCPUs. After that I faced no problem

arupjbasu
  • 121
  • 4
1

I was facing this issue because of an infinite loop in my hashCode method of the Entity.

Two entities had OneToMany relationship and I was using lombok @Data annotation which generates equals and hashcode implementation itself by calling hashCode() method for each attribute which was causing the infinite loop.

Heisenberg
  • 5,026
  • 2
  • 26
  • 37
0

Another reason why this is happening is due to excessive garbage collection, when garbage collection was running for a longer time within two executions of housekeeping thread, trying to free up some memory(e.g exactly when an application thread was running a 'select' query). Since the GC was blocking all application threads including the housekeeping thread, as such my suspicion is that the clock "leapt" due to that.

Cristian Balint
  • 81
  • 4