[FIXED] What could cause Hibernate flush for a single entity to take a very long time?

Issue

Background

I have an entity that I'm saving via Spring Data JPA's save method, using Hibernate. The entity is simple enough. It is just a collection of fields. The size is about 30KB, mainly due to the presence of two JSON fields.

The number of rows in the table is quite insignificant, maybe a thousand, as we are still in development. There are no indexes. It is a MySQL database. There are no 'related' entities (like foreign keys). All configurations are default.

The Problem

For some inserts, it takes a very long time: more than 10 seconds. Usually, it takes a few milliseconds. The source for this data is Hibernate's statistics log.

The logs look something like this.

org.hibernate.engine.internal.StatisticalLoggingSessionEventListener.end(StatisticalLoggingSessionEventListener.java:258) - Session Metrics {
906283 nanoseconds spent acquiring 1 JDBC connections;
0 nanoseconds spent releasing 0 JDBC connections;
179137263 nanoseconds spent preparing 1 JDBC statements;
4523687 nanoseconds spent executing 1 JDBC statements;
0 nanoseconds spent executing 0 JDBC batches;
0 nanoseconds spent performing 0 L2C puts;
0 nanoseconds spent performing 0 L2C hits;
0 nanoseconds spent performing 0 L2C misses;
17862368456 nanoseconds spent executing 1 flushes (flushing a total of 1 entities and 0 collections);
0 nanoseconds spent executing 0 partial-flushes (flushing a total of 0 entities and 0 collections)
}

I see two pain points, as indicated in the logs.

1. Time spent preparing JDBC statement
2. Time spent executing flushes

It is always 1 statement, and it always flushes one entity.

My question is, what could cause the operation to take such a long time (> 10 seconds) in some instances while it takes quite less (< 10 milliseconds) in others?

Solution

I see the following possible reasons for this:

1. Sloooooow network/datatransfer. For a single entity you are transferring quite some data over the wire. This shouldn't take that long, but if the database/network is under heavy load or doesn't have enough resources this could happen I guess.

2. Locks. Locks are always a good candidate when things take too long. The question though is: why does it take 18s and not forever.

3. Conversion. You create quite a bit of JSON. Does that need extra processing?

You should check for performance numbers on the database, the database server and also use a profiler on you application in order to distinguish between the three possible reasons.

Answered By - Jens Schauder
Answer Checked By - David Marino (JavaFixing Volunteer)