JUnit: Timestamps are compared as strings rather than parsed

[jrolli]

Bug Report

Summary

Our JUnit test suite compares the timestamps returned by Postgres and Noisepage as string literals rather than attempting to parse them before checking equivalence. This leads to trailing zeros in the decimal seconds portion becoming significant.

Environment

OS: Ubuntu 18.04 (LTS)

Compiler: GCC 7.0+ and Clang 8.0+.

Steps to Reproduce

Create a JUnit tracefile with a timestamp column and insert a timestamp with 5 decimal places in the seconds. Postgres will omit the trailing zero for microsecond precision, but Noisepage includes it.

Here is the base SQL code:

-- Generate tracefile with:
--     ant generate-trace -Dpath=sql/bug.sql -Ddb-url=jdbc:postgresql://localhost/postgres -Ddb-user=postgres -Ddb-password="postgres" -Doutput-name=bug.test && sed -i 's/nosort/rowsort/' traces/bug.test
CREATE TABLE bug (a TIMESTAMP);
INSERT INTO bug (a) VALUES ('2020-11-02 11:22:33.45678');
SELECT * FROM bug;
DROP TABLE bug;

Which becomes the following trace file:

statement ok
-- Generate tracefile with:

statement ok
--     ant generate-trace -Dpath=sql/bug.sql -Ddb-url=jdbc:postgresql://localhost/postgres -Ddb-user=postgres -Ddb-password="postgres" -Doutput-name=bug.test && sed -i 's/rowsort/rowsort/' traces/bug.test

statement ok
CREATE TABLE bug (a TIMESTAMP);

statement ok
INSERT INTO bug (a) VALUES ('2020-11-02 11:22:33.45678');

query  rowsort
SELECT * FROM bug;
----
2020-11-02 11:22:33.45678

statement ok
DROP TABLE bug;

Expected Behavior

The above tracefile should pass regardless of extra trailing zeros on the timestamp.

Actual Behavior

The test fails with the following error message:

+++ ==================================================================================================== +++
+++          TRACEFILE TEST: /home/jrollinson/Code/terrier/script/testing/junit/traces/bug.test          +++
+++ ==================================================================================================== +++

11-02-2020 15:06:09,169 [common.py:34] INFO : ****** start killing processes on port 15721 ******
11-02-2020 15:06:09,169 [common.py:34] INFO : ****** finish killing processes on port 15721 ******
11-02-2020 15:06:09,184 [test_server.py:96] INFO : Server start: /home/jrollinson/Code/terrier/build/bin/noisepage [PID=24106]
11-02-2020 15:06:09,324 [test_server.py:110] INFO : [2020-11-02 15:06:09.323] [network_logger] [info] Listening on networked socket with port 15721 [PID=24106]
11-02-2020 15:06:09,324 [test_server.py:110] INFO : [2020-11-02 15:06:09.324] [network_logger] [info] Listening on Unix domain socket with port 15721 [PID=24106]
11-02-2020 15:06:09,324 [test_server.py:112] INFO : DB process is verified as running
11-02-2020 15:06:14,970 [common.py:59] INFO : Buildfile: /home/jrollinson/Code/terrier/script/testing/junit/build.xml
11-02-2020 15:06:14,970 [common.py:59] INFO :
11-02-2020 15:06:14,971 [common.py:59] INFO : compile:
11-02-2020 15:06:14,971 [common.py:59] INFO : [javac] Compiling 1 source file to /home/jrollinson/Code/terrier/script/testing/junit/out
11-02-2020 15:06:14,971 [common.py:59] INFO : [javac] Note: /home/jrollinson/Code/terrier/script/testing/junit/src/moglib/CommandLine.java uses unchecked or unsafe operations.
11-02-2020 15:06:14,971 [common.py:59] INFO : [javac] Note: Recompile with -Xlint:unchecked for details.
11-02-2020 15:06:14,971 [common.py:59] INFO :
11-02-2020 15:06:14,971 [common.py:59] INFO : test-trace:
11-02-2020 15:06:14,971 [common.py:59] INFO : [java] Working Directory = /home/jrollinson/Code/terrier/script/testing/junit
11-02-2020 15:06:14,971 [common.py:59] INFO : [java] File name: /home/jrollinson/Code/terrier/script/testing/junit/traces/bug.test
11-02-2020 15:06:14,971 [common.py:59] INFO : [java] ╷
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] ├─ JUnit Jupiter ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │  └─ TracefileTest ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │     └─ generateTest() ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │        ├─ Line:1 | Expected statement ok ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │        ├─ Line:4 | Expected statement ok ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │        ├─ Line:7 | Expected statement ok ✔
11-02-2020 15:06:14,972 [common.py:59] INFO : [java] │        ├─ Line:10 | Expected statement ok ✔
11-02-2020 15:06:14,973 [common.py:59] INFO : [java] │        ├─ Line:13 | Hash:fec3aa9d988216000fd75ccc54e7ae25 ✘ Expected [2020-11-02 11:22:33.45678] but have [2020-11-02 11:22:33.456780]
11-02-2020 15:06:14,973 [common.py:59] INFO : [java] │        └─ Line:18 | Expected statement ok ✔
11-02-2020 15:06:14,973 [common.py:59] INFO : [java] └─ JUnit Vintage ✔
11-02-2020 15:06:14,973 [common.py:59] INFO : [java]
11-02-2020 15:06:14,973 [common.py:59] INFO : [java] Failures (1):
11-02-2020 15:06:14,973 [common.py:59] INFO : [java]   JUnit Jupiter:TracefileTest:generateTest():Line:13 | Hash:fec3aa9d988216000fd75ccc54e7ae25
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]     MethodSource [className = 'TracefileTest', methodName = 'generateTest', methodParameterTypes = '']
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]     => java.lang.Exception: Expected [2020-11-02 11:22:33.45678] but have [2020-11-02 11:22:33.456780]
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        TracefileTest.checkEquals(TracefileTest.java:159)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        TracefileTest.lambda$executeSelectQuery$0(TracefileTest.java:118)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.jupiter.engine.descriptor.JupiterTestDescriptor.executeAndMaskThrowable(JupiterTestDescriptor.java:141)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.jupiter.engine.descriptor.DynamicTestTestDescriptor.execute(DynamicTestTestDescriptor.java:41)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.jupiter.engine.descriptor.DynamicTestTestDescriptor.execute(DynamicTestTestDescriptor.java:24)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.lambda$executeRecursively$3(HierarchicalTestExecutor.java:112)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.platform.engine.support.hierarchical.SingleTestExecutor.executeSafely(SingleTestExecutor.java:66)
11-02-2020 15:06:14,974 [common.py:59] INFO : [java]        org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.executeRecursively(HierarchicalTestExecutor.java:108)
11-02-2020 15:06:14,975 [common.py:59] INFO : [java]        org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.execute(HierarchicalTestExecutor.java:79)
11-02-2020 15:06:14,975 [common.py:59] INFO : [java]        org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor$NodeExecutor.lambda$executeRecursively$0(HierarchicalTestExecutor.java:114)
11-02-2020 15:06:14,975 [common.py:59] INFO : [java]        [...]
11-02-2020 15:06:14,975 [common.py:59] INFO : [java]
11-02-2020 15:06:14,975 [common.py:59] INFO : [java] Test run finished after 734 ms
11-02-2020 15:06:14,975 [common.py:59] INFO : [java] [         4 containers found      ]
11-02-2020 15:06:14,975 [common.py:59] INFO : [java] [         0 containers skipped    ]
11-02-2020 15:06:14,975 [common.py:59] INFO : [java] [         4 containers started    ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         0 containers aborted    ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         4 containers successful ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         0 containers failed     ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         6 tests found           ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         0 tests skipped         ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         6 tests started         ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         0 tests aborted         ]
11-02-2020 15:06:14,976 [common.py:59] INFO : [java] [         5 tests successful      ]
11-02-2020 15:06:14,977 [common.py:59] INFO : [java] [         1 tests failed          ]
11-02-2020 15:06:14,977 [common.py:59] INFO : [java]
11-02-2020 15:06:14,977 [common.py:59] INFO :
11-02-2020 15:06:14,977 [common.py:59] INFO : BUILD FAILED
11-02-2020 15:06:14,977 [common.py:59] INFO : /home/jrollinson/Code/terrier/script/testing/junit/build.xml:63: Java returned: 1
11-02-2020 15:06:14,977 [common.py:59] INFO :
11-02-2020 15:06:14,977 [common.py:59] INFO : Total time: 5 seconds