Bug #16349: [API] Timestamp comparisons are incorrect when database session uses a non-UTC time zone - Arvados

Actions

Copy link

Bug #16349

closed

[API] Timestamp comparisons are incorrect when database session uses a non-UTC time zone

Added by Tom Clegg over 4 years ago. Updated over 4 years ago.

Status:

Resolved

Priority:

Normal

Assigned To:

Tom Clegg

Category:

API

Target version:

2020-05-06 Sprint

Story points:

Release:

Arvados 2.0.3

Release relationship:

Auto

Description

As an example, when we update the expiry time to Time.now + 5.minutes (as we do when caching a token from a remote cluster), depending on time zone configuration the expiry time that gets stored in the database might already be in the past, i.e., fail the expires_at > current_timestamp test.

This may explain why, given that we use "timestamp without time zone" columns:

create temporary table foo (
  twith timestamp with time zone,
  twithout timestamp without time zone
);

insert into foo values (current_timestamp, current_timestamp);

select * from foo;
             twith             |          twithout          
-------------------------------+----------------------------
 2020-04-22 12:40:20.796205-04 | 2020-04-22 12:40:20.796205

select extract(epoch from twith) - extract(epoch from twithout) from foo;
 ?column? 
----------
    14400

select '2020-04-22 15:36:15 UTC' - twith, '2020-04-22 15:36:15 UTC' - twithout from foo;
     ?column?     |    ?column?     
------------------+-----------------
 -00:01:45.153064 | 03:58:14.846936

set time zone 'UTC';
SET

select * from foo;
             twith             |          twithout          
-------------------------------+----------------------------
 2020-04-22 16:40:20.796205+00 | 2020-04-22 12:40:20.796205

Subtasks 1 (0 open — 1 closed)

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Subject changed from [API] Timestamp comparisons are incorrect when system time is not UTC to [API] Timestamp comparisons are incorrect when Rails and PostgreSQL are in different time zones

Actions

Copy link

Updated by Javier Bértoli over 4 years ago

The results seem to follow the docs and perhaps we're just not using it as expected?:

Note: The SQL standard requires that writing just timestamp be equivalent to timestamp without time zone, and PostgreSQL honors that behavior.

and

For timestamp with time zone, the internally stored value is always in UTC (Universal Coordinated Time, traditionally known as Greenwich Mean Time, GMT). An input value that has an explicit time zone specified is converted to UTC using the appropriate offset for that time zone. If no time zone is stated in the input string, then it is assumed to be in the time zone indicated by the system's timezone parameter, and is converted to UTC using the offset for the timezone zone.

When a timestamp with time zone value is output, it is always converted from UTC to the current timezone zone, and displayed as local time in that zone. To see the time in another time zone, either change timezone or use the AT TIME ZONE construct (see Section 9.9.3).

Conversions between timestamp without time zone and timestamp with time zone normally assume that the timestamp without time zone value should be taken or given as timezone local time. A different time zone can be specified for the conversion using AT TIME ZONE.

and also, from current_timestamp docs

Return value

The CURRENT_TIMESTAMP() function returns a TIMESTAMP WITH TIME ZONE that represents the date and time at which the transaction started.

So, if you use CURRENT_TIMESTAMP (that will be returned with TZ) and insert it into a timestamp without time zone field, you'll get a TZ drift.

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Target version set to 2020-05-06 Sprint

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Description updated (diff)

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Description updated (diff)

Javier Bértoli wrote:

The results seem to follow the docs and perhaps we're just not using it as expected?:

Yes, to be clear this is an Arvados bug, not a Rails or PostgreSQL bug.

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Subject changed from [API] Timestamp comparisons are incorrect when Rails and PostgreSQL are in different time zones to [API] Timestamp comparisons are incorrect when database session uses a non-UTC time zone

We're successfully saving UTC in the database, but when we say expires_at > current_timestamp in a query, the current_timestamp value gets typecast to a timestamp without time zone (to match expires_at's type) by dropping the tz offset (e.g., "-04").

If we change our condition to expires_at > current_timestamp at time zone 'UTC' then the comparison works as intended.

It looks like we can fix this class of bug by doing one or more of these:

Run set time zone 'UTC'; at the beginning of every database session (Rails, controller, websocket)
Change "current_timestamp" to "current_timestamp at time zone 'UTC'" in queries
Change column types from "timestamp" to "timestamptz"

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Release set to 33
Status changed from New to In Progress

Changing columns to timestamptz seems worthwhile, but since this is a candidate for a patchlevel release (2.0.3) I've avoided the migration (and any potential complications) for now. The "... AT TIME ZONE 'UTC'" change is enough to make the behavior correct.

Also, in a separate commit that we don't need to include in the patch release: The db_current_time() function (which gets called a lot) unnecessarily converts timestamps to localtime in PostgreSQL, then back to UTC in Rails. It doesn't seem to cause any problems (except maybe in unusual configurations and tight races during TZ transitions) but it seems pointless, so I removed it. Also removed a superfluous call to .to_time(), an ActiveSupport compatibility shim that either converts to localtime or does nothing, depending on some spooky action at a distance.

16349-non-utc-timestamps @ f84adca24070357d3da8092a2104a979efee7c76 -- developer-run-tests: #1827

16349-non-utc-timestamps @ f84adca24070357d3da8092a2104a979efee7c76 -- developer-run-tests: #1828

Actions

Copy link

Updated by Lucas Di Pentima over 4 years ago

Some questions:

Is the test addition at baf86998988 meant to expose the bug? I ran it on Jenkins (developer-run-tests-services-api: #1876 ) and it succeeded. If not, is it possible to write a test exposing the problem?
Is the date comparison for trashed objects also affected by this bug? I’m seeing the lib services/api/lib/sweep_trashed_objects.rb uses statement_timestamp() that seems to work similar to current_timestamp

Actions

Copy link

Updated by Tom Clegg over 4 years ago

Is the test addition at baf86998988 meant to expose the bug?

I've added "set time zone '-4'" to the top of the test so it fails in UTC as well, and rebased so you can test 20fd0e67d.

Is the date comparison for trashed objects also affected by this bug? I’m seeing the lib services/api/lib/sweep_trashed_objects.rb uses statement_timestamp() that seems to work similar to current_timestamp

Yes. The materialized view we use for permissions also uses a time function. Rather than recreate the view in a migration I've found a hook to set the DB connection timezone to UTC, and confirmed that the times stored in the materialized view are based on the time zone setting of the DB session that calls "refresh materialized view".

Doing the same thing in Go seems to be a bit more invasive (we'll need to check out a connection from the pool explicitly rather than let the sql library do it automatically) and we don't yet touch the materialized view from Go code, so I've left the "at time zone utc" fix in place on the Go side for now.

16349-non-utc-timestamps @ ae4eb84a350994daee72a21f380ea04bb2ca9f63 -- developer-run-tests: #1831

Actions

Copy link

#10