MySQL metadata locking and database transaction ending
Imagine having a tool that can automatically detect JPA and Hibernate performance issues. Wouldn’t that be just awesome?
Well, Hypersistence Optimizer is that tool! And it works with Spring Boot, Spring Framework, Jakarta EE, Java EE, Quarkus, or Play Framework.
So, enjoy spending your time on the things you love rather than fixing performance issues in your production system on a Saturday night!
Introduction
As previously explained, every SQL statement must be executed in the context of a database transaction. For modifying statements (e.g. INSERT
, UPDATE
, DELETE
), row-level locks must be taken to ensure recoverability and avoid the data anomalies.
Next, I’ll demonstrate what can happen when a database transaction is not properly ended.
The test that got blocked
To simplify unit tests, I’ve been using the following unit test utility to enroll a given set of operations in a database transaction:
protected void doInJPA(JPATransactionVoidFunction function) { EntityManager entityManager = null; EntityTransaction txn = null; try { entityManager = emf.createEntityManager(); function.beforeTransactionCompletion(); txn = entityManager.getTransaction(); txn.begin(); function.accept(entityManager); txn.commit(); } catch (RuntimeException e) { if ( txn != null && txn.isActive()) txn.rollback(); throw e; } finally { function.afterTransactionCompletion(); if (entityManager != null) { entityManager.close(); } } }
Considering we have the following JPA entity:
@Entity(name = "DateEvent") public class DateEvent { @Id @GeneratedValue private Long id; @Temporal(TemporalType.TIMESTAMP) @Column(name = "`timestamp`") private Calendar timestamp; public DateEvent() { } public DateEvent(Calendar timestamp) { this.timestamp = timestamp; } public Long getId() { return id; } public Calendar getTimestamp() { return timestamp; } }
The unit test looks like this:
@Test public void testEqualityAfterPersisting() { final Calendar calendar = new GregorianCalendar(); doInJPA(entityManager -> { entityManager.persist( new DateEvent( calendar ) ); } ); doInJPA(entityManager -> { DateEvent dateEvent = entityManager.createQuery( "select e from DateEvent e", DateEvent.class ) .getSingleResult(); assertEquals( calendar, dateEvent.getTimestamp() ); } ); }
This test has been running smoothly on HSQLDB, H2, Oracle, and PostgreSQL. On MySQL, the test got stuck, and the log looks like this:
DEBUG [main]: o.h.SQL - select next_val as id_val from hibernate_sequence for update DEBUG [main]: o.h.SQL - update hibernate_sequence set next_val= ? where next_val=? DEBUG [main]: o.h.SQL - insert into DateEvent (`timestamp`, id) values (?, ?) INFO [main]: o.h.h.i.QueryTranslatorFactoryInitiator - HHH000397: Using ASTQueryTranslatorFactory DEBUG [main]: o.h.SQL - select calendarwi0_.id as id1_0_, calendarwi0_.`timestamp` as timestam2_0_ from DateEvent calendarwi0_ INFO [main]: o.h.t.s.i.SchemaDropperImpl$DelayedDropActionImpl - HHH000477: Starting delayed drop of schema as part of SessionFactory shut-down' DEBUG [main]: o.h.SQL - drop table if exists DateEvent
The last log line indicates where the test got stuck.
For some reason, MySQL cannot drop the DateEvent
table.
The explanation
If you take a look at the transaction handling utility, you will find that a transaction is committed when the JPATransactionVoidFunction
callback runs without any exception and it rolls back on RuntimeException
.
In this case, the following assertion fails:
assertEquals( calendar, dateEvent.getTimestamp() );
But the ComparisonFailure
extends AssertionError
which in turn extends Error
. This way, the assertion failure is not caught by the catch
block and the transaction doesn’t get a chance to be rolled back.
The finally
block is always executed, even when an Error
is thrown. In the finally
block, the EntityManager
is closed, and, because I’m using hibernate.hbm2ddl.auto
set to create-drop
, Hibernate tries to delete the current schema.
But why does it block? This would be expected in a Two-Phase Locking Repeatable-Read implementation where a read operation takes a shared lock on a result set. But the InnoDB storage engine uses MVCC so readers should not block writers, and there are no concurrent transactions here.
In this example, the blocking happens when using a single database session. Even if the select statement doesn’t acquire a row-level lock, MySQL still uses metadata locking on every database transaction, and according to the MySQL documentation:
To ensure transaction [Serializability](https://vladmihalcea.com/serializability/), the server must not permit one session to perform a data definition language (DDL) statement on a table that is used in an uncompleted explicitly or implicitly started transaction in another session.
Because the transaction is not properly ended (either commit or rollback), the drop table
statement is stuck. The fix is simple. We just need to issue a rollback on any Throwable
so that we cover any RuntimeException
, Error
, or other Throwable
situations where we might still get a chance to execute the transaction rollback:
catch (Throwable e) { if ( txn != null && txn.isActive()) txn.rollback(); throw e; }
Now, when executing the test we get the following log:
DEBUG [main]: o.h.SQL - update hibernate_sequence set next_val= ? where next_val=? DEBUG [main]: o.h.SQL - insert into DateEvent (`timestamp`, id) values (?, ?) INFO [main]: o.h.h.i.QueryTranslatorFactoryInitiator - HHH000397: Using ASTQueryTranslatorFactory DEBUG [main]: o.h.SQL - select calendarwi0_.id as id1_0_, calendarwi0_.`timestamp` as timestam2_0_ from DateEvent calendarwi0_ INFO [main]: o.h.t.s.i.SchemaDropperImpl$DelayedDropActionImpl - HHH000477: Starting delayed drop of schema as part of SessionFactory shut-down' DEBUG [main]: o.h.SQL - drop table if exists DateEvent DEBUG [main]: o.h.SQL - drop table if exists hibernate_sequence java.lang.AssertionError: Expected :java.util.GregorianCalendar[time=1455774800060,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="Europe/Athens",offset=7200000,dstSavings=3600000,useDaylight=true,transitions=138,lastRule=java.util.SimpleTimeZone[id=Europe/Athens,offset=7200000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=2,startMonth=2,startDay=-1,startDayOfWeek=1,startTime=3600000,startTimeMode=2,endMode=2,endMonth=9,endDay=-1,endDayOfWeek=1,endTime=3600000,endTimeMode=2]],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2016,MONTH=1,WEEK_OF_YEAR=8,WEEK_OF_MONTH=3,DAY_OF_MONTH=18,DAY_OF_YEAR=49,DAY_OF_WEEK=5,DAY_OF_WEEK_IN_MONTH=3,AM_PM=0,HOUR=7,HOUR_OF_DAY=7,MINUTE=53,SECOND=20,MILLISECOND=60,ZONE_OFFSET=7200000,DST_OFFSET=0] Actual :java.util.GregorianCalendar[time=1455774800000,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="Europe/Athens",offset=7200000,dstSavings=3600000,useDaylight=true,transitions=138,lastRule=java.util.SimpleTimeZone[id=Europe/Athens,offset=7200000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=2,startMonth=2,startDay=-1,startDayOfWeek=1,startTime=3600000,startTimeMode=2,endMode=2,endMonth=9,endDay=-1,endDayOfWeek=1,endTime=3600000,endTimeMode=2]],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2016,MONTH=1,WEEK_OF_YEAR=8,WEEK_OF_MONTH=3,DAY_OF_MONTH=18,DAY_OF_YEAR=49,DAY_OF_WEEK=5,DAY_OF_WEEK_IN_MONTH=3,AM_PM=0,HOUR=7,HOUR_OF_DAY=7,MINUTE=53,SECOND=20,MILLISECOND=0,ZONE_OFFSET=7200000,DST_OFFSET=0]
The transaction is properly ended and the assertation failure, therefore, gets a chance to be logged.
I'm running an online workshop on the 11th of October about High-Performance SQL.If you enjoyed this article, I bet you are going to love my Book and Video Courses as well.
Conclusion
As a rule of thumb, a database transaction must always be ended (either committed or rolled back), no matter the outcome of a given data access layer operation (either successful or throwing an exception).
