Subject: Re: now() vs transaction_timestamp()
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: PostgreSQL Hackers <pgsql-hackers@postgresql.org>,
 Robert Haas <robertmhaas@gmail.com>
References: <6406dbd2-5d37-4cb6-6eb2-9c44172c7e7c@postgrespro.ru>
 <4268.1538747795@sss.pgh.pa.us> <4911.1538774725@sss.pgh.pa.us>
From: Konstantin Knizhnik <k.knizhnik@postgrespro.ru>
Message-ID: <9c78b24f-4ec9-e1dd-bdf6-e09e9b5f0e31@postgrespro.ru>
Date: Sat, 6 Oct 2018 15:51:17 +0300
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101
 Thunderbird/52.9.1
MIME-Version: 1.0
In-Reply-To: <4911.1538774725@sss.pgh.pa.us>
Content-Type: multipart/mixed;
 boundary="------------AB3AB136731E7C86C2181B77"
Content-Language: en-US
Precedence: bulk

This is a multi-part message in MIME format.
--------------AB3AB136731E7C86C2181B77
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 7bit


On 06.10.2018 00:25, Tom Lane wrote:
> I wrote:
>> Konstantin Knizhnik <k.knizhnik@postgrespro.ru> writes:
>>> Postgres documentation says that |"now()| is a traditional PostgreSQL
>>> equivalent to |transaction_timestamp()|".
>>> Also both use the same implementation.
>> Right.
>>> But them have different parallel safety property:
>> That seems like a bug/thinko.  I am not sure which property setting is
>> correct though.  It'd only be safe if the parallel-query infrastructure
>> transfers the relevant timestamp to workers, and I don't know if it does.
> The answer is that it doesn't; indeed, xactStartTimestamp is local inside
> xact.c, and it's easy to see by inspection that there is nothing at all
> that sets it except StartTransaction().  What is happening, if you do
>
> set force_parallel_mode to 1;
> select transaction_timestamp();
>
> is that the value you get back is the time that the parallel worker did
> StartTransaction().  It is easy to show that this is utterly broken:
> transaction_timestamp() holds still within a transaction until you set
> force_parallel_mode, and then it does not.
>
> regression=# begin;
> BEGIN
> regression=# select transaction_timestamp();
>       transaction_timestamp
> -------------------------------
>   2018-10-05 17:00:11.764019-04
> (1 row)
>
> regression=# select transaction_timestamp();
>       transaction_timestamp
> -------------------------------
>   2018-10-05 17:00:11.764019-04
> (1 row)
>
> regression=# select transaction_timestamp();
>       transaction_timestamp
> -------------------------------
>   2018-10-05 17:00:11.764019-04
> (1 row)
>
> regression=# set force_parallel_mode to 1;
> SET
> regression=# select transaction_timestamp();
>       transaction_timestamp
> -------------------------------
>   2018-10-05 17:00:21.983122-04
> (1 row)
>
> Looking at the related functions, I see that now() and
> statement_timestamp() are marked stable/restricted, which is OK, while
> clock_timestamp() and timeofday() are marked volatile/safe which seems odd
> but on reflection I think it's OK.  Their values wouldn't hold still in
> the parent process either, so there's no reason to disallow workers from
> running them.
>
> So transaction_timestamp() is definitely buggy, but we're not out of the
> woods yet: SQLValueFunction is treated as parallel-safe, but it also has
> some instances that are equivalent to transaction_timestamp and so do not
> work correctly.
>
> regression=# begin;
> BEGIN
> regression=# select current_time;
>      current_time
> --------------------
>   17:12:35.942968-04
> (1 row)
>
> regression=# select current_time;
>      current_time
> --------------------
>   17:12:35.942968-04
> (1 row)
>
> regression=# set force_parallel_mode to 1;
> SET
> regression=# select current_time;
>      current_time
> --------------------
>   17:12:55.462141-04
> (1 row)
>
> regression=# set force_parallel_mode to 0;
> SET
> regression=# select current_time;
>      current_time
> --------------------
>   17:12:35.942968-04
> (1 row)
>
> Ain't that fun?
>
> My initial thought was that we should just re-mark transaction_timestamp()
> as parallel-restricted and call it a day, but we'd then have to do the
> same for SQLValueFunction, which is not much fun because it does have
> variants that are parallel safe (and teaching max_parallel_hazard_walker
> which is which seems like a recipe for bugs).
>
> Also, while it might not be quite too late to force a catversion bump
> in v11, this is demonstrably also broken in v10, and we can't do that
> there.
>
> So maybe the right answer is to change the parallel mode infrastructure
> so it transmits xactStartTimestamp, making transaction_timestamp()
> retroactively safe, and then in HEAD only we could re-mark now() as
> safe.  We might as well do the same for statement_timestamp as well.
>
> Thoughts?
>
> 			regards, tom lane
Attached please find very small patch fixing the problem (propagating 
transaction and statement timestamps to workers).

--------------AB3AB136731E7C86C2181B77
Content-Type: text/x-patch;
 name="parallel_timestamp.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="parallel_timestamp.patch"

diff --git a/src/backend/access/transam/parallel.c b/src/backend/access/transam/parallel.c
index cdaa32e..abc41e7 100644
--- a/src/backend/access/transam/parallel.c
+++ b/src/backend/access/transam/parallel.c
@@ -87,6 +87,8 @@ typedef struct FixedParallelState
 	PGPROC	   *parallel_master_pgproc;
 	pid_t		parallel_master_pid;
 	BackendId	parallel_master_backend_id;
+	TimestampTz xact_ts;
+	TimestampTz stmt_ts;
 
 	/* Mutex protects remaining fields. */
 	slock_t		mutex;
@@ -318,6 +320,8 @@ InitializeParallelDSM(ParallelContext *pcxt)
 	fps->parallel_master_pgproc = MyProc;
 	fps->parallel_master_pid = MyProcPid;
 	fps->parallel_master_backend_id = MyBackendId;
+	fps->xact_ts = GetCurrentTransactionStartTimestamp();
+	fps->stmt_ts = GetCurrentStatementStartTimestamp();
 	SpinLockInit(&fps->mutex);
 	fps->last_xlog_end = 0;
 	shm_toc_insert(pcxt->toc, PARALLEL_KEY_FIXED, fps);
@@ -1351,6 +1355,9 @@ ParallelWorkerMain(Datum main_arg)
 	tstatespace = shm_toc_lookup(toc, PARALLEL_KEY_TRANSACTION_STATE, false);
 	StartParallelWorkerTransaction(tstatespace);
 
+	/* Restore current transaction and statement timestamps */
+	SetCurrentStartTimestamps(fps->xact_ts, fps->stmt_ts);
+
 	/* Restore combo CID state. */
 	combocidspace = shm_toc_lookup(toc, PARALLEL_KEY_COMBO_CID, false);
 	RestoreComboCIDState(combocidspace);
diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index 875be18..c8fc140 100644
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -675,6 +675,16 @@ GetCurrentCommandId(bool used)
 }
 
 /*
+ *	SetCurrentStartTimestamps
+ */
+void
+SetCurrentStartTimestamps(TimestampTz xact_ts, TimestampTz stmt_ts)
+{
+	 xactStartTimestamp = xact_ts;
+	 stmtStartTimestamp = stmt_ts;
+}
+
+/*
  *	GetCurrentTransactionStartTimestamp
  */
 TimestampTz
diff --git a/src/include/access/xact.h b/src/include/access/xact.h
index 083e879..05afa36 100644
--- a/src/include/access/xact.h
+++ b/src/include/access/xact.h
@@ -356,6 +356,7 @@ extern TransactionId GetCurrentTransactionId(void);
 extern TransactionId GetCurrentTransactionIdIfAny(void);
 extern TransactionId GetStableLatestTransactionId(void);
 extern SubTransactionId GetCurrentSubTransactionId(void);
+extern void SetCurrentStartTimestamps(TimestampTz xact_ts, TimestampTz stmt_ts);
 extern void MarkCurrentTransactionIdLoggedIfAny(void);
 extern bool SubTransactionIsActive(SubTransactionId subxid);
 extern CommandId GetCurrentCommandId(bool used);
diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat
index 8e4145f..dfa8395 100644
--- a/src/include/catalog/pg_proc.dat
+++ b/src/include/catalog/pg_proc.dat
@@ -2595,13 +2595,13 @@
   proname => 'timetzdate_pl', prolang => '14', prorettype => 'timestamptz',
   proargtypes => 'timetz date', prosrc => 'select ($2 + $1)' },
 { oid => '1299', descr => 'current transaction time',
-  proname => 'now', provolatile => 's', proparallel => 'r',
+  proname => 'now', provolatile => 's', proparallel => 's',
   prorettype => 'timestamptz', proargtypes => '', prosrc => 'now' },
 { oid => '2647', descr => 'current transaction time',
   proname => 'transaction_timestamp', provolatile => 's',
   prorettype => 'timestamptz', proargtypes => '', prosrc => 'now' },
 { oid => '2648', descr => 'current statement time',
-  proname => 'statement_timestamp', provolatile => 's', proparallel => 'r',
+  proname => 'statement_timestamp', provolatile => 's', proparallel => 's',
   prorettype => 'timestamptz', proargtypes => '',
   prosrc => 'statement_timestamp' },
 { oid => '2649', descr => 'current clock time',

--------------AB3AB136731E7C86C2181B77--