LP #1381966: Server side prepared statements leads to potential off-by-second timestamp on slaves

**Reported in Launchpad by Jacques Grove last update 30-10-2017 05:51:58

I have Percona Server 5.6.21 installed on RHEL6, the following packages:

Percona-Server-client-56-5.6.21-rel69.0.el6.x86_64
Percona-Server-server-56-5.6.21-rel69.0.el6.x86_64
Percona-Server-shared-56-5.6.21-rel69.0.el6.x86_64

I have the following table:

> show create table test.t1\G

• • • • • • • • • • • • • • • • • • • • • • • • • • • 1. row ***************************
                                                      Table: t1
                                                      Create Table: CREATE TABLE `t1` (
                                                      `created_time` timestamp NULL DEFAULT NULL
                                                      ) ENGINE=InnoDB DEFAULT CHARSET=utf8

Testcase:

> truncate test.t1;
Query OK, 0 rows affected (0.02 sec)

Run the following code using mysql-connector-java 5.1.32 from MySQL. Note the use of server-side prepared statements:

import java.sql.Connection;
import java.sql.Timestamp;
import java.sql.DriverManager;
import java.sql.PreparedStatement;

class Test {
public static void main(String[] args) {
Connection conn;
try

{ Class.forName("com.mysql.jdbc.Driver").newInstance(); String url = "jdbc:mysql://127.0.0.1:3306/test?useServerPrepStmts=true"; conn = DriverManager.getConnection(url, "test", "test"); PreparedStatement stmt = conn.prepareStatement("INSERT INTO t1 (created_time) values (?)"); stmt.setTimestamp(1, new Timestamp(1300883333501L)); stmt.execute(); }

catch (Exception e)

{ System.out.println("Exception: "+e); e.printStackTrace(); }

}
}

Note the result in the table:

> select * from test.t1\G

• • • • • • • • • • • • • • • • • • • • • • • • • • • 1. row ***************************
                                                      created_time: 2011-03-23 12:28:54

Now, run the same code, but without server-side prepared statements in the driver options:

import java.sql.Connection;
import java.sql.Timestamp;
import java.sql.DriverManager;
import java.sql.PreparedStatement;

class Test {
public static void main(String[] args) {
Connection conn;
try

{ Class.forName("com.mysql.jdbc.Driver").newInstance(); String url = "jdbc:mysql://127.0.0.1:3306/test"; conn = DriverManager.getConnection(url, "test", "test"); PreparedStatement stmt = conn.prepareStatement("INSERT INTO t1 (created_time) values (?)"); stmt.setTimestamp(1, new Timestamp(1300883333501L)); stmt.execute(); }

catch (Exception e)

{ System.out.println("Exception: "+e); e.printStackTrace(); }

}
}

Inspect the database again; result is as expected:

> select * from test.t1\G

• • • • • • • • • • • • • • • • • • • • • • • • • • • 1. row ***************************
                                                      created_time: 2011-03-23 12:28:54
                                                    • 2. row ***************************
                                                      created_time: 2011-03-23 12:28:54

However, now examine the binary/replication log on the server (binlog_format=STATEMENT):

#141016 9:16:23 server id 9993 end_log_pos 7065 CRC32 0x08aa0438 Query thread_id=81 exec_time=0 error_code=0
SET TIMESTAMP=1413450983/!/;
INSERT INTO t1 (created_time) values ('2011-03-23 12:28:53')
/!/;

1. at 7065
   #141016 9:16:23 server id 9993 end_log_pos 7096 CRC32 0x11ceda38 Xid = 1268
   COMMIT/!/;
2. at 7096
   #141016 9:18:13 server id 9993 end_log_pos 7183 CRC32 0xad39e8c8 Query thread_id=83 exec_time=0 error_code=0
   SET TIMESTAMP=1413451093/!/;
   BEGIN
   /!/;
3. at 7183
   #141016 9:18:13 server id 9993 end_log_pos 7329 CRC32 0x039bbb0b Query thread_id=83 exec_time=0 error_code=0
   SET TIMESTAMP=1413451093/!/;
   INSERT INTO t1 (created_time) values ('2011-03-23 12:28:53.501')
   /!/;
4. at 7329
   #141016 9:18:13 server id 9993 end_log_pos 7360 CRC32 0x6c565aeb Xid = 1282
   COMMIT/!/;

Note that the for the first test, while using server-side prepared statements, the fractional part of the timestamp was dropped before getting to the binary log. When not using server-side prepared statements (2nd test), the fractional part of the timestamp is preserved into the binary log. From the timestamps in the table, you can see the problem. With server-side prepared statements the master will end up with the correctly rounded timestamp ('2011-03-23 12:28:54'), but any slave will end up with the truncated timestamp, which in this case is 1 second behind ('2011-03-23 12:28:53').

The workaround of not using server-side prepared statements is not an option. In our case we have alleviated the issue by rounding the timestamp in the code to the nearest second, but this should really "just work".

I have not looked deeper into whether this is a JDBC driver or a server issue.