A problem tracing experience of application support

Salad Lam - Jan 31 - - Dev Community

Notice

I wrote this article and was originally published on Qiita on 30 August 2022.


Symptom

A user reported that in the saved report of a application, all fields related to time are changed, changed to 1 hour earlier to original value. This happened recently and there was no problem in the past.

Simple to say, the application is build by Spring Boot, and details are:

  • Java 8
  • Spring MCV
  • Spring Data JPA
  • JPA (By Hibernate)
  • MySQL

Investigation direction: Time zone

In the UK, time zone will be changed 2 times per year. And there is one hour difference between two time zones. So first of all I looked into the points related to time zone.

When the default time zone of MySQL server is the same as the time zone of Java application (British summer time when time of writing), time input is correctly saved into the database. But when the default time zone of MySQL server is set to one hour earlier (Greenwich Mean Time), time saved to the database is one hour earlier than inputed value.

To find out which part is out of expectation

And then looked into MySQL. The table column stored time is defined as TIME, according to the document, MySQL will not alter the value before stored. And after testing, the value is correctly stored by running insert SQL statements without using Prepared Statements.

It is time to move back to the application. Following data process path

  1. Entity instance created and binded with values of HTTP request in the controller. The time fields of the entity are LocalTime class, it is not affected by the time zone setting of the application. It is easy to check, just dump the values of the entity created to the logger. As expected, the value correctly passed.
  2. Entity persisted in the database by generating SQL commands by JPA provider. By setting following values in application.properties.
logging.level.org.hibernate.SQL=debug
logging.level.org.hibernate.type.descriptor.sql=trace
Enter fullscreen mode Exit fullscreen mode

The generated SQL and parameter binding can be viewed. And the value correctly passed to the MySQL JDBC driver.

Unexpected behavior of MySQL JDBC driver

When I traced the program flow in MySQL JDBC driver, finally I found out where the value was altered (in com.mysql.cj.ClientPreparedQueryBindings#setTime(int, java.sql.Time, java.util.Calendar)). Here is the detail.

. . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . . .
Terabox Video Player