Coprocessor does not handle ambiguous time zones correctly

[morgo]

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. What did you do?

Using the bikeshare sample database:

mysql> delete from trips where start_date < '2017-01-01 00:00:00';
ERROR 1105 (HY000): other error: unknown error StringError("[src/coprocessor/dag/executor/mod.rs:239]: unknown error StringError(\"[src/coprocessor/codec/mysql/time/mod.rs:95]: \\\'2010-11-7 1:0:8.000000000\\\' is not a valid datetime\")")
mysql> explain delete from trips where start_date < '2017-01-01 00:00:00';
+---------------------+-------------+------+------------------------------------------------------------+
| id                  | count       | task | operator info                                              |
+---------------------+-------------+------+------------------------------------------------------------+
| TableReader_6       | 19117643.00 | root | data:Selection_5                                           |
| └─Selection_5       | 19117643.00 | cop  | lt(bikeshare.trips.start_date, 2017-01-01 00:00:00.000000) |
|   └─TableScan_4     | 19117643.00 | cop  | table:trips, range:[-inf,+inf], keep order:false           |
+---------------------+-------------+------+------------------------------------------------------------+
3 rows in set (0.00 sec)

2. What did you expect to see?

Success.

3. What did you see instead?

Error.

4. What version of TiDB are you using (tidb-server -V or run select tidb_version(); on TiDB)?

mysql> select tidb_version()\G
*************************** 1. row ***************************
tidb_version(): Release Version: v2.1.0-rc.2-18-g334e9254d
Git Commit Hash: 334e9254d3ccf4d12d53e97c96c00d12bbf3f073
Git Branch: newmaster
UTC Build Time: 2018-09-20 08:29:30
GoVersion: go version go1.11 linux/amd64
Race Enabled: false
TiKV Min Version: 2.1.0-alpha.1-ff3dd160846b7d1aed9079c389fc188f7f5ea13e
Check Table Before Drop: false
1 row in set (0.00 sec)

[breezewish]

I tried with latest TiDB and TiKV (and the TiDB version you given) and cannot reproduce it. Would you like to post your TiKV version? A detail reproduce step is more appreciated!

[morgo]

The reproduction step was load the data and execute the delete. I will try updrading my TiKV version:

morgo@ryzen:~/tidb/tidb-latest-linux-amd64$ ./bin/tikv-server --version
TiKV 
Release Version:   2.1.0-rc.2
Git Commit Hash:   ad1d9f3684148c727d25b9cdf148fa535850b87e
Git Commit Branch: master
UTC Build Time:    2018-09-18 05:08:00
Rust Version:      rustc 1.29.0-nightly (4f3c7a472 2018-07-17)

[morgo]

Confirming that after upgrading I can still reproduce:

mysql> delete from trips where start_date < '2017-01-01 00:00:00';
ERROR 1105 (HY000): other error: unknown error StringError("[src/coprocessor/dag/executor/mod.rs:239]: unknown error StringError(\"[src/coprocessor/codec/mysql/time/mod.rs:95]: \\\'2010-11-7 1:0:8.000000000\\\' is not a valid datetime\")")

mysql> select tidb_version()\G
*************************** 1. row ***************************
tidb_version(): Release Version: v2.1.0-rc.2-25-g16864f95b
Git Commit Hash: 16864f95b47f859ed6104555ccff0387abdc2429
Git Branch: newmaster
UTC Build Time: 2018-09-23 11:04:53
GoVersion: go version go1.11 linux/amd64
Race Enabled: false
TiKV Min Version: 2.1.0-alpha.1-ff3dd160846b7d1aed9079c389fc188f7f5ea13e
Check Table Before Drop: false
1 row in set (0.00 sec)

morgo@ryzen:~/tidb/tidb-latest-linux-amd64$ ./bin/tikv-server --version
TiKV 
Release Version:   2.1.0-rc.2
Git Commit Hash:   eae3f9dcfeba8f3adba02eae361d13966049d26a
Git Commit Branch: master
UTC Build Time:    2018-09-22 05:10:34
Rust Version:      rustc 1.29.0-nightly (4f3c7a472 2018-07-17)

[breezewish]

Would you like to dump your data directory and sent it to me? I still cannot reproduce it.

By reproduce, I mean, drop the database, import according to docs, and perform a DELETE SQL.

[morgo]

@breeswish I believe it is fixed in master, I'm waiting for the daily tarball to be generated so I can try it out and report back :-) Should only be a couple of hours now.

[morgo]

I can still reproduce the error - but I think it's timezone related! See below. Here are the steps to reproduce:

1. [Download latest tarball.](wget http://download.pingcap.org/tidb-latest-linux-amd64.tar.gz)
2. Start pd, tikv, and then tidb (all on one server):

   ./bin/pd-server --data-dir=pd
   ./bin/tikv-server --pd="127.0.0.1:2379" --data-dir=tikv
   ./bin/tidb-server --store=tikv --path="127.0.0.1:2379"

3. Load data per documentation.

I am starting with an empty data directory. After the data is loaded, I run the delete statement straight away. A select statement works equally well of course:

mysql> select count(*) from trips where start_date < '2017-01-01 00:00:00';
ERROR 1105 (HY000): other error: unknown error StringError("[src/coprocessor/dag/executor/mod.rs:239]: unknown error StringError(\"[src/coprocessor/codec/mysql/time/mod.rs:95]: \\\'2016-11-6 1:0:8.000000000\\\' is not a valid datetime\")")
mysql> EXPLAIN select count(*) from trips where start_date < '2017-01-01 00:00:00';
+--------------------------+-------------+------+------------------------------------------------------------+
| id                       | count       | task | operator info                                              |
+--------------------------+-------------+------+------------------------------------------------------------+
| StreamAgg_20             | 1.00        | root | funcs:count(col_0)                                         |
| └─TableReader_21         | 1.00        | root | data:StreamAgg_9                                           |
|   └─StreamAgg_9          | 1.00        | cop  | funcs:count(1)                                             |
|     └─Selection_19       | 6562368.86  | cop  | lt(bikeshare.trips.start_date, 2017-01-01 00:00:00.000000) |
|       └─TableScan_18     | 10277677.00 | cop  | table:trips, range:[-inf,+inf], keep order:false           |
+--------------------------+-------------+------+------------------------------------------------------------+
5 rows in set (0.01 sec)

---

Some other attempts:

mysql> select @@time_zone;
+-------------+
| @@time_zone |
+-------------+
| SYSTEM      |
+-------------+
1 row in set (0.00 sec)

mysql> select count(*) from trips where start_date < '2017-11-11 00:00:00';
ERROR 1105 (HY000): other error: unknown error StringError("[src/coprocessor/dag/executor/mod.rs:239]: unknown error StringError(\"[src/coprocessor/codec/mysql/time/mod.rs:95]: \\\'2016-11-6 1:0:8.000000000\\\' is not a valid datetime\")")
mysql> select count(*) from trips where start_date < '2017-11-11 00:00:00';
ERROR 1105 (HY000): other error: unknown error StringError("[src/coprocessor/dag/executor/mod.rs:239]: unknown error StringError(\"[src/coprocessor/codec/mysql/time/mod.rs:95]: \\\'2015-11-1 1:0:17.000000000\\\' is not a valid datetime\")")
mysql> set time_zone='+00:00'
    -> ;
Query OK, 0 rows affected (0.01 sec)

mysql> select count(*) from trips where start_date < '2017-11-11 00:00:00';
+----------+
| count(*) |
+----------+
|  9941709 |
+----------+
1 row in set (2.43 sec)

My timezone is MDT:

$ date
Wed Sep 26 19:34:54 MDT 2018

[breezewish]

wow. @morgo I might know the cause. There should be a DST change at your time zone at that time (notice the date is Nov 6). TiKV currently does not support ambiguous time (those human readable time that can be interpreted to 2 different timestamps caused by DST shifting back 1 hour).

[morgo]

That makes sense - DST change is around Nov 6th. If it is not immediately fixable, it would be nice to present a better error message.

I typically use UTC for server deployments, but this is my desktop :-)

[morgo]

This issue was fixed in tikv. Verified against daily build.