The database time is 14 hours slow, Mybatis said. I don't carry this pot!

Colleagues feedback a question: Mybatis was inserted into the database yesterday. Is it because there is a problem generating the code generated by Mybatis reverse engineering?

As we all know, I am very interested in such bugs. My intuition tells me that it should not be the Bug of Mybatis, but probably the problem of time zone.

Good. Today we can take you to check bugs again and see what skills you can Get from this Bug check.

The problem of this study is a little profound, but the conclusion is very important. Let's go!

Problem conjecture

When colleagues feed back questions, they bring their own conjecture: is it because the database field is set to datetime? Is it caused by inconsistent types in the code generated by Mybatis reverse engineering?

My colleague also changed datetime to varchar... I immediately stopped him and said: check the problem first and then the solution. I also took time to have a look in the afternoon.

Problem verification

The first step is to check the database field type, which is datetime. No problem.

Step 2: check that the type in the entity class is java.util.Date. No problem.

The third step is to reproduce the Bug.

In the step of Bug reproduction, unit testing is used. In other words, I discussed the charm of unit testing with my friends before. Now I like unit testing more and more.

The project is based on Spring Boot, and the unit test is as follows (the code has been desensitized):

@SpringBootTest
class DateTimeTests {

    @Resource
    private UserMapper userMapper;

    @Test
    public void testDate(){
        User  user = new User();
        // Omit other fields
        user.setCreateDate(new Date());
        userMapper.insertSelective(user);
    }
}

Execute a unit test to view the data inserted in the database. The Bug reappearance time is indeed the time of the previous day, 14 hours different from the current time.

After the above three steps of troubleshooting, it is verified that the types in the database fields and codes are OK. Unit tests also recurred problems. My colleagues didn't deceive me. Seeing is believing, ha ha~

Therefore, it is basically determined that it is a time zone problem.

Time zone troubleshooting

Check server time

Log in to the test server, execute the date command, and check the server time and time zone:

[root@xxx ~]# date
2021 Thursday, November 25, 2009:26:25 CST
[root@xxx ~]# date -R
Thu, 25 Nov 2021 09:33:34 +0800

The display time is the current time, using CST time, and the last + 0800, that is, East Zone 8, no problem.

Check database time zone

Connect to the database and execute the show command:

show variables like '%time_zone%';

+----------------------------+
|Variable         | Value |
+----------------------------+
|system_time_zone    |CST    |
|time_zone          |SYSTEM |

system_time_zone: global parameter, system time zone. When MySQL is started, the time zone of the current system will be checked and the global parameter system will be set according to the system time zone_ time_ The value of the zone. The value is CST, which is consistent with the time zone of the system time.

time_zone: global parameter. It sets the time zone of each connection session. The default is SYSTEM. The global parameter SYSTEM is used_ time_ The value of the zone.

Check time zone in code

Add the code to print the time zone in the unit test method:

@Test
    public void testDate(){
        System.out.println(System.getProperty("user.timezone"));
        User  user = new User();
        // Omit other fields
        user.setCreateDate(new Date());
        userMapper.insertSelective(user);
    }

The time zone printed is:

Asia/Shanghai

In other words, the UTC time zone is used in Java for business logic processing, and it is also the time of the East eighth zone.

So what's the problem?

Basic presentation of problems

After the above investigation, it is basically determined that it is a time zone problem. Here, I would like to add the above related knowledge points about time zones.

UTC time

UTC time: World coordinated time (UTC) is the main time standard used by different countries in the world to adjust the clock and time, that is, the time in the zero time zone.

UTC, Coordinated Universal Time is a standard, not a time zone. UTC is a universal time standard. All parts of the world agree to coordinate their own time synchronously, which is also the source of UTC's name: Universal Coordinated Time.

CST time

CST time: central standard time.

CST can represent the following four different time zones:

  • Central Standard Time (USA) UT-6:00, USA
  • Central Standard Time (Australia) UT+9:30, Australia
  • China Standard Time UT+8:00, China
  • Cuba Standard Time UT-4:00, Cuba

Analyze again

Obviously, it has nothing to do with UTC time, it's just a time standard. System in Mysql_ time_ Zone is CST, and CST can represent four different time zones. What time zone does Mysql treat it as?

By simple calculation, the Chinese time is UT+8:00 and the US time is UT-6:00. When the Chinese time is introduced and directly converted to the US time (without considering the time zone), the time is 14 hours slower.

Now that you know the problem, there is a solution.

Solution

The above problems can be solved at the database level and code level.

Scheme 1: modify database time zone

Since Mysql misunderstood the time zone specified by CST, set it to the correct one.

Connect to the Mysql database and set the correct time zone:

[root@xxxxx ~]# mysql -uroot -p
mysql> set global time_zone = '+8:00';
mysql> set time_zone = '+8:00'
mysql> flush privileges;

Execute the show command again:

show variables like '%time_zone%';

+----------------------------+
|Variable         | Value |
+----------------------------+
|system_time_zone    |CST    |
|time_zone          |+08:00 |

You can see that the time zone has become the time of the East eighth district. The unit test is performed again and the problem is solved.

In this scheme, you can also directly modify the my.cnf file of MySQL to specify the time zone.

Scheme 2: modify database connection parameters

When the code connects to the database, specify the time zone used by the parameter.

After the URL of the configuration database connection, add the time zone specified on serverTimezone=Asia/Shanghai:

url: jdbc:mysql://xx.xx.xx.xx:3306/db_name?useUnicode=true&characterEncoding=utf8&autoReconnect=true&serverTimezone=Asia/Shanghai

The problem can also be solved by performing the unit test again.

Is the problem over?

After the above analysis and operation, the problem of time zone has been solved. Is that the end of the problem? Why?

In order to verify the time zone problem, a field is created in the database with wrong time zone. The field type is datetime and the default value is CURRENT_TIMESTAMP.

Then, insert a record and let Mysql automatically generate the time of the field. Guess what the time of the field is? Chinese time zone.

Isn't it amazing? Why is the same CST time zone, the time automatically generated by the system is correct, and there is a time difference in the time of code insertion?

Does Mysql understand the CST time zone as U.S. time, or does Mybatis, connection pool or driver understand it as U.S. time?

The play begins

In order to trace what went wrong in the code, first open the debug log of Mybatis to see what the value was when insert ing:

2021-11-25 11:05:28.367 [|1637809527983|] DEBUG 20178 --- [   scheduling-1] c.h.s.m.H.listByCondition                : ==> Parameters: 2021-11-25 11:05:27(String), 0(Integer), 1(Integer), 2(Integer), 3(Integer), 4(Integer)

The above are the parameters for insert, that is, there is no problem with the time at the Mybatis level. Exclude one.

Is that a connection pool or driver problem? The connection pool itself has little to do with the specific operation of database connection, so you can directly check the driver.

Mybatis defines the date field type as TIMESTAMP in xml. After skimming the source code of mysql-connector-Java-8.0.x, it is found that SqlTimestampValueFactory is used to process the TIMESTAMP type.

Set a breakpoint on the construction method of SqlTimestampValueFactory and execute the unit test:

You can clearly see that Calendar sets the time zone to Locale.US, that is, U.S. time, the time zone to CST and the offset to - 21600000- 21600000 units are milliseconds, converted into hours, which is exactly "- 6:00", which is exactly 14 hours different from "GMT+08:00" Beijing time.

Thus, the call link is eventually traced upward. The TimeZone comes from the serverTimeZone of NativeServerSession, and the value of serverTimeZone is set by the configureTimezone method of NativeProtocol class.

public void configureTimezone() {
        String configuredTimeZoneOnServer = this.serverSession.getServerVariable("time_zone");

        if ("SYSTEM".equalsIgnoreCase(configuredTimeZoneOnServer)) {
            configuredTimeZoneOnServer = this.serverSession.getServerVariable("system_time_zone");
        }

        String canonicalTimezone = getPropertySet().getStringProperty(PropertyKey.serverTimezone).getValue();

        if (configuredTimeZoneOnServer != null) {
            // user can override this with driver properties, so don't detect if that's the case
            if (canonicalTimezone == null || StringUtils.isEmptyOrWhitespaceOnly(canonicalTimezone)) {
                try {
                    canonicalTimezone = TimeUtil.getCanonicalTimezone(configuredTimeZoneOnServer, getExceptionInterceptor());
                } catch (IllegalArgumentException iae) {
                    throw ExceptionFactory.createException(WrongArgumentException.class, iae.getMessage(), getExceptionInterceptor());
                }
            }
        }

        if (canonicalTimezone != null && canonicalTimezone.length() > 0) {
            // Set TimeZone here
            this.serverSession.setServerTimeZone(TimeZone.getTimeZone(canonicalTimezone));

            if (!canonicalTimezone.equalsIgnoreCase("GMT") && this.serverSession.getServerTimeZone().getID().equals("GMT")) {
                throw ExceptionFactory.createException(WrongArgumentException.class, Messages.getString("Connection.9", new Object[] { canonicalTimezone }),
                        getExceptionInterceptor());
            }
        }

    }

debug tracks the above code and displays the following information:

So far, by obtaining the canonicalTimezone value, we can see the role of configuring serverTimezone=Asia/Shanghai after the URL. The first code block above gets the time_ The value of zone, get system in the second code block_ time_ The value of the zone. This is consistent with the value obtained by querying the database.

Because the parameter serverTimezone=Asia/Shanghai is not added to the url when the problem occurs, the canonicalTimezone is null. Subsequently, the TimeUtil.getCanonicalTimezone method was invoked in logic.

public static String getCanonicalTimezone(String timezoneStr, ExceptionInterceptor exceptionInterceptor) {
        if (timezoneStr == null) {
            return null;
        }

        timezoneStr = timezoneStr.trim();

        // handle '+/-hh:mm' form ...
        if (timezoneStr.length() > 2) {
            if ((timezoneStr.charAt(0) == '+' || timezoneStr.charAt(0) == '-') && Character.isDigit(timezoneStr.charAt(1))) {
                return "GMT" + timezoneStr;
            }
        }

        synchronized (TimeUtil.class) {
            if (timeZoneMappings == null) {
                loadTimeZoneMappings(exceptionInterceptor);
            }
        }

        String canonicalTz;
        if ((canonicalTz = timeZoneMappings.getProperty(timezoneStr)) != null) {
            return canonicalTz;
        }

        throw ExceptionFactory.createException(InvalidConnectionAttributeException.class,
                Messages.getString("TimeUtil.UnrecognizedTimezoneId", new Object[] { timezoneStr }), exceptionInterceptor);
    }

In the above code, we finally come to loadtimezone mappings (exception interceptor); method:

private static void loadTimeZoneMappings(ExceptionInterceptor exceptionInterceptor) {
        timeZoneMappings = new Properties();
        try {
            timeZoneMappings.load(TimeUtil.class.getResourceAsStream(TIME_ZONE_MAPPINGS_RESOURCE));
        } catch (IOException e) {
            throw ExceptionFactory.createException(Messages.getString("TimeUtil.LoadTimeZoneMappingError"), exceptionInterceptor);
        }
        // bridge all Time Zone ids known by Java
        for (String tz : TimeZone.getAvailableIDs()) {
            if (!timeZoneMappings.containsKey(tz)) {
                timeZoneMappings.put(tz, tz);
            }
        }
    }

This method loads the values in the configuration file "/ com/mysql/cj/util/TimeZoneMapping.properties". After conversion, the corresponding CST in timezonemapping is "CST".

Finally, the canonicalTimezone is "CST", and the TimeZone is obtained through the TimeZone.getTimeZone(canonicalTimezone) method.

That is, the value of TimeZone.getTimeZone("CST") is us time. Write a unit test to verify:

public class TimeZoneTest {

    @Test
    public void testTimeZone(){
        System.out.println(TimeZone.getTimeZone("CST"));
    }
}

Print results:

sun.util.calendar.ZoneInfo[id="CST",offset=-21600000,dstSavings=3600000,useDaylight=true,transitions=235,lastRule=java.util.SimpleTimeZone[id=CST,offset=-21600000,dstSavings=3600000,useDaylight=true,startYear=0,startMode=3,startMonth=2,startDay=8,startDayOfWeek=1,startTime=7200000,startTimeMode=0,endMode=3,endMonth=10,endDay=1,endDayOfWeek=1,endTime=7200000,endTimeMode=0]]

Obviously, after this method is imported into CST, the default is us time.

So far, the cause of the problem is basically clear:

  • Server set in Mysql_ time_zone is CST, time_zone is SYSTEM.
  • Mysql driven query to time_ The zone is SYSTEM, so server is used_ time_ The value of zone is "CST".
  • The value obtained by TimeZone.getTimeZone("CST") in JDK is the U.S. time zone;
  • Calendar Class constructed in U.S. time zone;
  • SqlTimestampValueFactory uses the above Calendar to format the Chinese time obtained by the system, and the time difference problem occurs;
  • The final reflection on the database data is the wrong time.

serverVariables variable

Further extension, server_time_zone and time_zone are from the serverVariables variable of NativeSession, which is initialized in the loadServerVariables method of NativeSession. The key code is as follows:

if (versionMeetsMinimum(5, 1, 0)) {
                StringBuilder queryBuf = new StringBuilder(versionComment).append("SELECT");
                queryBuf.append("  @@session.auto_increment_increment AS auto_increment_increment");
                queryBuf.append(", @@character_set_client AS character_set_client");
                queryBuf.append(", @@character_set_connection AS character_set_connection");
                queryBuf.append(", @@character_set_results AS character_set_results");
                queryBuf.append(", @@character_set_server AS character_set_server");
                queryBuf.append(", @@collation_server AS collation_server");
                queryBuf.append(", @@collation_connection AS collation_connection");
                queryBuf.append(", @@init_connect AS init_connect");
                queryBuf.append(", @@interactive_timeout AS interactive_timeout");
                if (!versionMeetsMinimum(5, 5, 0)) {
                    queryBuf.append(", @@language AS language");
                }
                queryBuf.append(", @@license AS license");
                queryBuf.append(", @@lower_case_table_names AS lower_case_table_names");
                queryBuf.append(", @@max_allowed_packet AS max_allowed_packet");
                queryBuf.append(", @@net_write_timeout AS net_write_timeout");
                queryBuf.append(", @@performance_schema AS performance_schema");
                if (!versionMeetsMinimum(8, 0, 3)) {
                    queryBuf.append(", @@query_cache_size AS query_cache_size");
                    queryBuf.append(", @@query_cache_type AS query_cache_type");
                }
                queryBuf.append(", @@sql_mode AS sql_mode");
                queryBuf.append(", @@system_time_zone AS system_time_zone");
                queryBuf.append(", @@time_zone AS time_zone");
                if (versionMeetsMinimum(8, 0, 3) || (versionMeetsMinimum(5, 7, 20) && !versionMeetsMinimum(8, 0, 0))) {
                    queryBuf.append(", @@transaction_isolation AS transaction_isolation");
                } else {
                    queryBuf.append(", @@tx_isolation AS transaction_isolation");
                }
                queryBuf.append(", @@wait_timeout AS wait_timeout");

                NativePacketPayload resultPacket = sendCommand(this.commandBuilder.buildComQuery(null, queryBuf.toString()), false, 0);
                Resultset rs = ((NativeProtocol) this.protocol).readAllResults(-1, false, resultPacket, false, null,
                        new ResultsetFactory(Type.FORWARD_ONLY, null));
                Field[] f = rs.getColumnDefinition().getFields();
                if (f.length > 0) {
                    ValueFactory<String> vf = new StringValueFactory(this.propertySet);
                    Row r;
                    if ((r = rs.getRows().next()) != null) {
                        for (int i = 0; i < f.length; i++) {
                            this.protocol.getServerSession().getServerVariables().put(f[i].getColumnLabel(), r.getValue(i, vf));
                        }
                    }
                }

In the append operation of StringBuilder above, there are two values of "@ @ time_zone AS time_zone" and "@ @ system_time_zone AS system_time_zone". Then query the database, obtain the value from the database, and put it into serverVariables.

debug again:

It can be seen that the value of system_time_zone is CST.

Similarly, the value of time_zone is "SYSTEM".

According to the tips in the code, splice the same SQL as the code to query the database:

select @@time_zone;
SYSTEM

The value is indeed "SYSTEM". At this time, we come up with another method to query the current time zone of Mysql.

So far, the investigation of the problem has been completed perfectly. Let's breathe a sigh of relief~~~

Summary

In the above troubleshooting process, unit testing is used many times, which is also the charm of unit testing. It uses the simplest code, the lightest logic and the most time-saving way to verify and track errors.

Review the knowledge points used and learned in the above Bug Troubleshooting:

  • Linux date viewing, time zone viewing and derivation how to configure the time zone;
  • Mysql time zone view;
  • Spring Boot unit test;
  • Java time zone acquisition;
  • UTC time and CST time;
  • Two solutions to the time zone problem;
  • Read and debug Mysql driver source code;
  • TimeZone.getTimeZone("CST") the default time zone is the U.S. time zone;
  • Basic process logic for handling time zone issues in Mysql driver;
  • Mybatis debug log related printing;
  • Other relevant knowledge.

What did you learn from this Bug search article? If you have a little inspiration, don't be stingy and give me a praise!

About the blogger: the author of the technical book "inside of SpringBoot technology", loves to study technology and write technical dry goods articles.

The official account: "new horizon of procedures", the official account of bloggers, welcome the attention.

Technical exchange: please contact blogger wechat: zhuan2quan

<center> "new horizon of procedures", official account of a 100% dry cargo </center>

Tags: MySQL Mybatis

Posted on Fri, 26 Nov 2021 20:49:24 -0500 by doremi