transction_timestamp() inside of procedures

Started by Bruce Momjianover 7 years ago32 messages
#1Bruce Momjian
bruce@momjian.us

This function shows that only clock_timestamp() advances inside a
procedure, not statement_timestamp() or transaction_timestamp():

CREATE OR REPLACE PROCEDURE test_timestamp () AS $$
DECLARE
str TEXT;
BEGIN
WHILE TRUE LOOP
-- clock_timestamp() is updated on every loop
SELECT clock_timestamp() INTO str;
RAISE NOTICE 'clock %', str;
SELECT statement_timestamp() INTO str;
RAISE NOTICE 'statement %', str;
SELECT transaction_timestamp() INTO str;
RAISE NOTICE 'transaction %', str;
COMMIT;

PERFORM pg_sleep(2);
END LOOP;
END
$$ LANGUAGE plpgsql;

CALL test_timestamp();
NOTICE: clock 2018-09-20 19:38:22.575794-04
NOTICE: statement 2018-09-20 19:38:22.575685-04
NOTICE: transaction 2018-09-20 19:38:22.575685-04

--> NOTICE: clock 2018-09-20 19:38:24.578027-04
NOTICE: statement 2018-09-20 19:38:22.575685-04
NOTICE: transaction 2018-09-20 19:38:22.575685-04

This surprised me since I expected a new timestamp after commit. Is
this something we want to change or document? Are there other
per-transaction behaviors we should adjust?

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#2Michael Paquier
michael@paquier.xyz
In reply to: Bruce Momjian (#1)
Re: transction_timestamp() inside of procedures

On Thu, Sep 20, 2018 at 07:40:40PM -0400, Bruce Momjian wrote:

This surprised me since I expected a new timestamp after commit. Is
this something we want to change or document? Are there other
per-transaction behaviors we should adjust?

I don't quite follow your argument here. clock_timestamp is known to be
volatile, while the two others are stable, so its value can change
within a transaction.
--
Michael

#3Andres Freund
andres@anarazel.de
In reply to: Michael Paquier (#2)
Re: transction_timestamp() inside of procedures

Hi,

On 2018-09-21 13:55:36 +0900, Michael Paquier wrote:

On Thu, Sep 20, 2018 at 07:40:40PM -0400, Bruce Momjian wrote:

This surprised me since I expected a new timestamp after commit. Is
this something we want to change or document? Are there other
per-transaction behaviors we should adjust?

I don't quite follow your argument here. clock_timestamp is known to be
volatile, while the two others are stable, so its value can change
within a transaction.

Isn't the point that transaction_timestamp() does *not* currently change
its value, even though the transaction (although not the outermost
statement) has finished?

I think Bruce has quite the point here.

Greetings,

Andres Freund

#4Michael Paquier
michael@paquier.xyz
In reply to: Andres Freund (#3)
Re: transction_timestamp() inside of procedures

On Thu, Sep 20, 2018 at 10:12:06PM -0700, Andres Freund wrote:

Isn't the point that transaction_timestamp() does *not* currently change
its value, even though the transaction (although not the outermost
statement) has finished?

Ouch, yes. I see the point now. Indeed that's strange to not have a
new transaction timestamp after commit within the DO block..

I need a break of a couple of minutes.
--
Michael

#5Bruce Momjian
bruce@momjian.us
In reply to: Michael Paquier (#4)
Re: transction_timestamp() inside of procedures

On Fri, Sep 21, 2018 at 02:34:25PM +0900, Michael Paquier wrote:

On Thu, Sep 20, 2018 at 10:12:06PM -0700, Andres Freund wrote:

Isn't the point that transaction_timestamp() does *not* currently change
its value, even though the transaction (although not the outermost
statement) has finished?

Ouch, yes. I see the point now. Indeed that's strange to not have a
new transaction timestamp after commit within the DO block..

So, this puts us in an odd position. Right now everyone knows that
statement_timestamp() is only changed by the outer statement, i.e., a
SELECT in a function doesn't change statement_timestamp(). So, there
is an argument that transaction_timestamp() should do the same and not
change in a function --- in fact, if it does change, it would mean that
transaction_timestamp() changes in a function, but statement_timestamp()
doesn't --- that seems very odd. It would mean that new statements in a
function don't change statement_timestamp(), but new transctions in a
function do --- again, very odd.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#6Bruce Momjian
bruce@momjian.us
In reply to: Bruce Momjian (#5)
Re: transction_timestamp() inside of procedures

On Fri, Sep 21, 2018 at 06:28:22AM -0400, Bruce Momjian wrote:

On Fri, Sep 21, 2018 at 02:34:25PM +0900, Michael Paquier wrote:

On Thu, Sep 20, 2018 at 10:12:06PM -0700, Andres Freund wrote:

Isn't the point that transaction_timestamp() does *not* currently change
its value, even though the transaction (although not the outermost
statement) has finished?

Ouch, yes. I see the point now. Indeed that's strange to not have a
new transaction timestamp after commit within the DO block..

So, this puts us in an odd position. Right now everyone knows that
statement_timestamp() is only changed by the outer statement, i.e., a
SELECT in a function doesn't change statement_timestamp(). So, there
is an argument that transaction_timestamp() should do the same and not
change in a function --- in fact, if it does change, it would mean that
transaction_timestamp() changes in a function, but statement_timestamp()
doesn't --- that seems very odd. It would mean that new statements in a
function don't change statement_timestamp(), but new transctions in a
function do --- again, very odd.

Sorry I was unclear about this. It is only the third loop that proves
it is not advancing:

NOTICE: clock 2018-09-21 18:01:00.63704-04
NOTICE: statement 2018-09-21 18:01:00.636509-04
NOTICE: transaction 2018-09-21 18:01:00.636509-04

NOTICE: clock 2018-09-21 18:01:02.640033-04
NOTICE: statement 2018-09-21 18:01:00.636509-04
NOTICE: transaction 2018-09-21 18:01:00.636509-04

NOTICE: clock 2018-09-21 18:01:04.642266-04
NOTICE: statement 2018-09-21 18:01:00.636509-04
--> NOTICE: transaction 2018-09-21 18:01:00.636509-04

Keep in mind that transaction_timestamp() is CURRENT_TIMESTAMP.

I have always thought of clock/statement/transation as decreasing levels
of time precision, and it might be odd to change that. I don't think we
want to change the behavior of statement_timestamp() in procedures, so
that kind of requires us not to change transaction_timestamp() inside of
procedures.

However, no change in behavior causes the problem that if you have a
transaction block using transaction_timestamp() or CURRENT_TIMESTAMP,
and you move it into a procedure, the behavior of those functions will
change, but this was always true of moving statement_timestamp() into a
function, and I have never heard a complaint about that.

Does the SQL standard have anything to say about CURRENT_TIMESTAMP in
procedures? Do we need another function that does advance on procedure
commit?

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#7Bruce Momjian
bruce@momjian.us
In reply to: Bruce Momjian (#6)
Re: transction_timestamp() inside of procedures

On Fri, Sep 21, 2018 at 06:35:02PM -0400, Bruce Momjian wrote:

Does the SQL standard have anything to say about CURRENT_TIMESTAMP in
procedures? Do we need another function that does advance on procedure
commit?

I found a section in the SQL standards that talks about it, but I don't
understand it. Can I quote the paragraph here?

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#8Andres Freund
andres@anarazel.de
In reply to: Bruce Momjian (#1)
Re: transction_timestamp() inside of procedures

Hi,

On 2018-09-20 19:40:40 -0400, Bruce Momjian wrote:

This function shows that only clock_timestamp() advances inside a
procedure, not statement_timestamp() or transaction_timestamp():

CREATE OR REPLACE PROCEDURE test_timestamp () AS $$
DECLARE
str TEXT;
BEGIN
WHILE TRUE LOOP
-- clock_timestamp() is updated on every loop
SELECT clock_timestamp() INTO str;
RAISE NOTICE 'clock %', str;
SELECT statement_timestamp() INTO str;
RAISE NOTICE 'statement %', str;
SELECT transaction_timestamp() INTO str;
RAISE NOTICE 'transaction %', str;
COMMIT;

PERFORM pg_sleep(2);
END LOOP;
END
$$ LANGUAGE plpgsql;

CALL test_timestamp();
NOTICE: clock 2018-09-20 19:38:22.575794-04
NOTICE: statement 2018-09-20 19:38:22.575685-04
NOTICE: transaction 2018-09-20 19:38:22.575685-04

--> NOTICE: clock 2018-09-20 19:38:24.578027-04
NOTICE: statement 2018-09-20 19:38:22.575685-04
NOTICE: transaction 2018-09-20 19:38:22.575685-04

This surprised me since I expected a new timestamp after commit. Is
this something we want to change or document? Are there other
per-transaction behaviors we should adjust?

ISTM this is an issue that belongs on the open items list. Peter, could
you comment?

Greetings,

Andres Freund

#9David G. Johnston
david.g.johnston@gmail.com
In reply to: Bruce Momjian (#7)
Re: transction_timestamp() inside of procedures

On Sat, Sep 22, 2018 at 5:27 PM, Bruce Momjian <bruce@momjian.us> wrote:

On Fri, Sep 21, 2018 at 06:35:02PM -0400, Bruce Momjian wrote:

Does the SQL standard have anything to say about CURRENT_TIMESTAMP in
procedures? Do we need another function that does advance on procedure
commit?

I found a section in the SQL standards that talks about it, but I don't
understand it. Can I quote the paragraph here?

I've seen others do it; and small sections of copyrighted material posted
for commentary or critique would likely be covered by "fair use" exemptions.

David J.

#10Andres Freund
andres@anarazel.de
In reply to: Andres Freund (#8)
Re: transction_timestamp() inside of procedures

On 2018-09-25 14:50:02 -0700, Andres Freund wrote:

ISTM this is an issue that belongs on the open items list. Peter, could
you comment?

Done so, per discussion with the rest of the RMT.

#11Bruce Momjian
bruce@momjian.us
In reply to: David G. Johnston (#9)
Re: transction_timestamp() inside of procedures

On Tue, Sep 25, 2018 at 03:01:31PM -0700, David G. Johnston wrote:

On Sat, Sep 22, 2018 at 5:27 PM, Bruce Momjian <bruce@momjian.us> wrote:

On Fri, Sep 21, 2018 at 06:35:02PM -0400, Bruce Momjian wrote:

Does the SQL standard have anything to say about CURRENT_TIMESTAMP in
procedures?� Do we need another function that does advance on procedure
commit?

I found a section in the SQL standards that talks about it, but I don't
understand it.� Can I quote the paragraph here?

I've seen others do it; and small sections of copyrighted material posted for
commentary or critique would likely be covered by "fair use" exemptions.

Well, it is an entire paragraph, so it might be too much. If you
download the zip file here:

http://www.wiscorp.com/sql200n.zip

and open 5CD2-02-Foundation-2006-01.pdf, at the top of page 289 under
General Rules, paragraph label 3 has the description. It talks about
procedure statements and trigger functions, which seems promising.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#12Peter Eisentraut
peter.eisentraut@2ndquadrant.com
In reply to: Bruce Momjian (#6)
Re: transction_timestamp() inside of procedures

On 22/09/2018 00:35, Bruce Momjian wrote:

I have always thought of clock/statement/transation as decreasing levels
of time precision, and it might be odd to change that. I don't think we
want to change the behavior of statement_timestamp() in procedures, so
that kind of requires us not to change transaction_timestamp() inside of
procedures.

However, no change in behavior causes the problem that if you have a
transaction block using transaction_timestamp() or CURRENT_TIMESTAMP,
and you move it into a procedure, the behavior of those functions will
change, but this was always true of moving statement_timestamp() into a
function, and I have never heard a complaint about that.

Right. Statement timestamp actually means the timestamp of the
top-level statement, because it's set where the protocol interaction
happens. The transaction timestamp is implemented as the statement
timestamp when the transaction starts, but for intra-procedural
transactions, the statement timestamp does not advance, so the
transaction timestamp doesn't change.

Note that this also affects the xact_start column in pg_stat_activity.

We could certainly address this by adding three or four or five new
timestamps that cover all these varieties. But perhaps it's worth
asking what these timestamps are useful for and which ones we really need.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#13Bruce Momjian
bruce@momjian.us
In reply to: Peter Eisentraut (#12)
Re: transction_timestamp() inside of procedures

On Wed, Sep 26, 2018 at 02:38:25PM +0200, Peter Eisentraut wrote:

On 22/09/2018 00:35, Bruce Momjian wrote:

I have always thought of clock/statement/transation as decreasing levels
of time precision, and it might be odd to change that. I don't think we
want to change the behavior of statement_timestamp() in procedures, so
that kind of requires us not to change transaction_timestamp() inside of
procedures.

However, no change in behavior causes the problem that if you have a
transaction block using transaction_timestamp() or CURRENT_TIMESTAMP,
and you move it into a procedure, the behavior of those functions will
change, but this was always true of moving statement_timestamp() into a
function, and I have never heard a complaint about that.

Right. Statement timestamp actually means the timestamp of the
top-level statement, because it's set where the protocol interaction
happens. The transaction timestamp is implemented as the statement
timestamp when the transaction starts, but for intra-procedural
transactions, the statement timestamp does not advance, so the
transaction timestamp doesn't change.

Note that this also affects the xact_start column in pg_stat_activity.

We could certainly address this by adding three or four or five new
timestamps that cover all these varieties. But perhaps it's worth
asking what these timestamps are useful for and which ones we really need.

Frankly, we might be fine with just documenting it and see if anyone
complains. I think the top-level statement part is obvious, but I am
not sure the top-level transaction part is. This is because it is clear
the top-level statement causes all the lower statements underneath it,
but the top-level transaction doesn't control all the transactions under
it in the same way.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#14Tom Lane
tgl@sss.pgh.pa.us
In reply to: Bruce Momjian (#13)
Re: transction_timestamp() inside of procedures

Bruce Momjian <bruce@momjian.us> writes:

On Wed, Sep 26, 2018 at 02:38:25PM +0200, Peter Eisentraut wrote:

We could certainly address this by adding three or four or five new
timestamps that cover all these varieties. But perhaps it's worth
asking what these timestamps are useful for and which ones we really need.

Frankly, we might be fine with just documenting it and see if anyone
complains.

I'm not for adding a bunch of new action-start timestamps without very
clear use-cases for them, because each one we add means more gettimeday()
overhead that might or might not ever be useful.

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

regards, tom lane

#15Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Bruce Momjian (#11)
Re: transction_timestamp() inside of procedures

On 2018-Sep-25, Bruce Momjian wrote:

Well, it is an entire paragraph, so it might be too much. If you
download the zip file here:

http://www.wiscorp.com/sql200n.zip

and open 5CD2-02-Foundation-2006-01.pdf, at the top of page 289 under
General Rules, paragraph label 3 has the description. It talks about
procedure statements and trigger functions, which seems promising.

I have the 2011 draft, not the 2006 one; you seem to be referring to
<datetime value function> (which is 6.32 in the 2011 draft I have).
General rule 3 is entirely unreadable, and is followed by this note:

WG3:LCY-025 took no action on the preceding instance of general containment.
It was felt that this rule is too complicated, to the point of being virtually
unintelligible. In addition, the rule does not recognize that <datetime value
function>s can be evaluated implicitly as <default option>s. It is believed
that this rule does not reflect actual practice and should be rewritten to
align it with implementations. Note that Subclause 15.1, “Effect of opening a
cursor”, also has a General Rule on this subject. See
Possible Problem FND-992 .

In SQL2016, this rule was removed completely.

I don't think this offers any practical guidance.

--
Álvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#16Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Tom Lane (#14)
Re: transction_timestamp() inside of procedures

On 2018-Sep-26, Tom Lane wrote:

Bruce Momjian <bruce@momjian.us> writes:

On Wed, Sep 26, 2018 at 02:38:25PM +0200, Peter Eisentraut wrote:

We could certainly address this by adding three or four or five new
timestamps that cover all these varieties. But perhaps it's worth
asking what these timestamps are useful for and which ones we really need.

Frankly, we might be fine with just documenting it and see if anyone
complains.

I'm not for adding a bunch of new action-start timestamps without very
clear use-cases for them, because each one we add means more gettimeday()
overhead that might or might not ever be useful.

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

Really? I thought it was practically obvious that for transaction-
controlling procedures, the transaction timestamp would not necessarily
be aligned with the statement timestamp. The surprise would come
together with the usage of the new feature, so existing users would not
be surprised in any way.

I do wonder how do other systems behave in this area, though.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#17Tom Lane
tgl@sss.pgh.pa.us
In reply to: Alvaro Herrera (#16)
Re: transction_timestamp() inside of procedures

Alvaro Herrera <alvherre@2ndquadrant.com> writes:

On 2018-Sep-26, Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

Really? I thought it was practically obvious that for transaction-
controlling procedures, the transaction timestamp would not necessarily
be aligned with the statement timestamp. The surprise would come
together with the usage of the new feature, so existing users would not
be surprised in any way.

Nope. That's the same poor reasoning we've fallen into in some other
cases, of assuming that "the user" is a point source of knowledge.
But DBMSes tend to interact with lots of different code. If some part
of application A starts using intraprocedure transactions, and then
application B breaks because it wasn't expecting to see xact_start
later than query_start in pg_stat_activity, you've still got a problem.

I'm also a bit hesitant to invent new semantics here based on the
assumption that we've got only one, nonoverlapping, top-level transaction
at a time. It's not terribly hard to imagine suspend-and-resume-
transaction features coming down the pike at some point. What will
we do then? We'll already have a definitional issue for xact_start,
but it'll get worse the more different kinds of xact_start we have.

regards, tom lane

#18Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Tom Lane (#17)
Re: transction_timestamp() inside of procedures

On 2018-Sep-26, Tom Lane wrote:

Alvaro Herrera <alvherre@2ndquadrant.com> writes:

On 2018-Sep-26, Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

Really? I thought it was practically obvious that for transaction-
controlling procedures, the transaction timestamp would not necessarily
be aligned with the statement timestamp. The surprise would come
together with the usage of the new feature, so existing users would not
be surprised in any way.

Nope. That's the same poor reasoning we've fallen into in some other
cases, of assuming that "the user" is a point source of knowledge.
But DBMSes tend to interact with lots of different code. If some part
of application A starts using intraprocedure transactions, and then
application B breaks because it wasn't expecting to see xact_start
later than query_start in pg_stat_activity, you've still got a problem.

While that's true, I think it's also highly hypothetical.

What could be the use for the transaction timestamp? I think one of the
most important uses (at least in pg_stat_activity) is to verify that
transactions are not taking excessively long time to complete; that's
known to cause all sorts of trouble in Postgres, and probably other
DBMSs too. If we don't accurately measure what it really is, and
instead keep the compatibility behavior, we risk panicking people
because they think some transaction has been running for a long time
when in reality it's just a very long procedure which commits frequently
enough not to be a problem.

I'm also a bit hesitant to invent new semantics here based on the
assumption that we've got only one, nonoverlapping, top-level transaction
at a time. It's not terribly hard to imagine suspend-and-resume-
transaction features coming down the pike at some point. What will
we do then? We'll already have a definitional issue for xact_start,
but it'll get worse the more different kinds of xact_start we have.

This is even more hypothetical.

If we can have a list or stack of running transactions, clearly a single
timestamp value is not sufficient. We could report a single value for
"the oldest transaction", or perhaps "the transaction that's currently
active". But if we wanted to be really thorough about it, we'd need to
report the list of timestamps for each running transaction in the
current session. However, I don't think those future developments would
change what the transaction timestamp is, namely, the start of the
current transaction, not the start of the statement that (after possibly
many iterations) gave rise to the current transaction.

--
�lvaro Herrera https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#19Andres Freund
andres@anarazel.de
In reply to: Alvaro Herrera (#18)
Re: transction_timestamp() inside of procedures

On 2018-09-26 12:54:43 -0300, Alvaro Herrera wrote:

On 2018-Sep-26, Tom Lane wrote:

Alvaro Herrera <alvherre@2ndquadrant.com> writes:

On 2018-Sep-26, Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

Really? I thought it was practically obvious that for transaction-
controlling procedures, the transaction timestamp would not necessarily
be aligned with the statement timestamp. The surprise would come
together with the usage of the new feature, so existing users would not
be surprised in any way.

Nope. That's the same poor reasoning we've fallen into in some other
cases, of assuming that "the user" is a point source of knowledge.
But DBMSes tend to interact with lots of different code. If some part
of application A starts using intraprocedure transactions, and then
application B breaks because it wasn't expecting to see xact_start
later than query_start in pg_stat_activity, you've still got a problem.

While that's true, I think it's also highly hypothetical.

What could be the use for the transaction timestamp? I think one of the
most important uses (at least in pg_stat_activity) is to verify that
transactions are not taking excessively long time to complete; that's
known to cause all sorts of trouble in Postgres, and probably other
DBMSs too. If we don't accurately measure what it really is, and
instead keep the compatibility behavior, we risk panicking people
because they think some transaction has been running for a long time
when in reality it's just a very long procedure which commits frequently
enough not to be a problem.

+1

I'm also a bit hesitant to invent new semantics here based on the
assumption that we've got only one, nonoverlapping, top-level transaction
at a time. It's not terribly hard to imagine suspend-and-resume-
transaction features coming down the pike at some point. What will
we do then? We'll already have a definitional issue for xact_start,
but it'll get worse the more different kinds of xact_start we have.

This is even more hypothetical.

If we can have a list or stack of running transactions, clearly a single
timestamp value is not sufficient. We could report a single value for
"the oldest transaction", or perhaps "the transaction that's currently
active". But if we wanted to be really thorough about it, we'd need to
report the list of timestamps for each running transaction in the
current session. However, I don't think those future developments would
change what the transaction timestamp is, namely, the start of the
current transaction, not the start of the statement that (after possibly
many iterations) gave rise to the current transaction.

+1

Greetings,

Andres Freund

#20Daniel Verite
daniel@manitou-mail.org
In reply to: Tom Lane (#14)
Re: transction_timestamp() inside of procedures

Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp.

To me it's more surprising to start a new transaction and having
transaction_timestamp() still pointing at the start of a previous
transaction.
This feels like a side-effect of being spawned by a procedure,
and an exception to what transaction_timestamp() normally means
or meant until now.

OTOH transaction_timestamp() being possibly newer than
statement_timestamp() seems like a normal consequence of
transactions being created intra-statement.

+1 for transaction_timestamp() and pg_stat_activity being updated
to follow intra-procedure transactions.

Best regards,
--
Daniel Vérité
PostgreSQL-powered mailer: http://www.manitou-mail.org
Twitter: @DanielVerite

#21Peter Eisentraut
peter.eisentraut@2ndquadrant.com
In reply to: Alvaro Herrera (#18)
Re: transction_timestamp() inside of procedures

On 26/09/2018 17:54, Alvaro Herrera wrote:

What could be the use for the transaction timestamp? I think one of the
most important uses (at least in pg_stat_activity) is to verify that
transactions are not taking excessively long time to complete; that's
known to cause all sorts of trouble in Postgres, and probably other
DBMSs too. If we don't accurately measure what it really is, and
instead keep the compatibility behavior, we risk panicking people
because they think some transaction has been running for a long time
when in reality it's just a very long procedure which commits frequently
enough not to be a problem.

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#22Peter Eisentraut
peter.eisentraut@2ndquadrant.com
In reply to: Peter Eisentraut (#21)
1 attachment(s)
Re: transction_timestamp() inside of procedures

On 26/09/2018 23:48, Peter Eisentraut wrote:

On 26/09/2018 17:54, Alvaro Herrera wrote:

What could be the use for the transaction timestamp? I think one of the
most important uses (at least in pg_stat_activity) is to verify that
transactions are not taking excessively long time to complete; that's
known to cause all sorts of trouble in Postgres, and probably other
DBMSs too. If we don't accurately measure what it really is, and
instead keep the compatibility behavior, we risk panicking people
because they think some transaction has been running for a long time
when in reality it's just a very long procedure which commits frequently
enough not to be a problem.

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

Attached is a rough implementation.

I'd be mildly in favor of doing this, but we have mentioned tradeoffs in
this thread.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Attachments:

0001-Advance-transaction-timestamp-in-intra-procedure-tra.patchtext/plain; charset=UTF-8; name=0001-Advance-transaction-timestamp-in-intra-procedure-tra.patch; x-mac-creator=0; x-mac-type=0Download
From 2a8c214479adb4b98c8b6c95875d8bebd88cb940 Mon Sep 17 00:00:00 2001
From: Peter Eisentraut <peter_e@gmx.net>
Date: Fri, 28 Sep 2018 09:33:24 +0200
Subject: [PATCH] Advance transaction timestamp in intra-procedure transactions

---
 src/backend/access/transam/xact.c | 19 ++++++++++++-------
 1 file changed, 12 insertions(+), 7 deletions(-)

diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index 9aa63c8792..245735420c 100644
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -1884,14 +1884,19 @@ StartTransaction(void)
 	TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId);
 
 	/*
-	 * set transaction_timestamp() (a/k/a now()).  We want this to be the same
-	 * as the first command's statement_timestamp(), so don't do a fresh
-	 * GetCurrentTimestamp() call (which'd be expensive anyway).  Also, mark
-	 * xactStopTimestamp as unset.
-	 */
-	xactStartTimestamp = stmtStartTimestamp;
-	xactStopTimestamp = 0;
+	 * set transaction_timestamp() (a/k/a now()).  Normally, we want this to
+	 * be the same as the first command's statement_timestamp(), so don't do a
+	 * fresh GetCurrentTimestamp() call (which'd be expensive anyway).  But
+	 * for transactions started inside statements (e.g., procedure calls), we
+	 * want to advance the timestamp.
+	 */
+	if (xactStartTimestamp < stmtStartTimestamp)
+		xactStartTimestamp = stmtStartTimestamp;
+	else
+		xactStartTimestamp = GetCurrentTimestamp();
 	pgstat_report_xact_timestamp(xactStartTimestamp);
+	/* Mark xactStopTimestamp as unset. */
+	xactStopTimestamp = 0;
 
 	/*
 	 * initialize current transaction state fields
-- 
2.19.0

#23Bruce Momjian
bruce@momjian.us
In reply to: Daniel Verite (#20)
Re: transction_timestamp() inside of procedures

On Wed, Sep 26, 2018 at 09:23:58PM +0200, Daniel Verite wrote:

Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp.

To me it's more surprising to start a new transaction and having
transaction_timestamp() still pointing at the start of a previous
transaction.
This feels like a side-effect of being spawned by a procedure,
and an exception to what transaction_timestamp() normally means
or meant until now.

OTOH transaction_timestamp() being possibly newer than
statement_timestamp() seems like a normal consequence of
transactions being created intra-statement.

Yes, that is a good point. My thought has always been that statements
are inside of transactions, but the opposite is now possible.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#24Peter Eisentraut
peter.eisentraut@2ndquadrant.com
In reply to: Peter Eisentraut (#22)
Re: transction_timestamp() inside of procedures

On 28/09/2018 09:35, Peter Eisentraut wrote:

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

Attached is a rough implementation.

I'd be mildly in favor of doing this, but we have mentioned tradeoffs in
this thread.

So do we want to do this or not?

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

#25Bruce Momjian
bruce@momjian.us
In reply to: Peter Eisentraut (#24)
Re: transction_timestamp() inside of procedures

On Tue, Oct 2, 2018 at 10:55:56AM +0200, Peter Eisentraut wrote:

On 28/09/2018 09:35, Peter Eisentraut wrote:

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

Attached is a rough implementation.

I'd be mildly in favor of doing this, but we have mentioned tradeoffs in
this thread.

So do we want to do this or not?

I thought some more about this. I think there are a few issues:

1 Utility: since you can't use CALL in a transaction block, our
current code will always have transaction_timestamp() and
statement_timestamp() as identical in a procedure. Having
transaction_timestamp() advance on COMMIT gives users a new ability.

2 Surprise: What do people use transaction_timestamp() for and what
behavior would be most expected?

3 Other databases: How do other database systems handle this, and the
SQL standard?

Based on 1 and 2, I suggest we change transaction_timestamp() to advance
on COMMIT in procedure, and document this. I have no idea on #3.

--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://enterprisedb.com

+ As you are, so once was I.  As I am, so you will be. +
+                      Ancient Roman grave inscription +
#26Andres Freund
andres@anarazel.de
In reply to: Peter Eisentraut (#24)
Re: transction_timestamp() inside of procedures

Hi,

On 2018-10-02 10:55:56 +0200, Peter Eisentraut wrote:

On 28/09/2018 09:35, Peter Eisentraut wrote:

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

Attached is a rough implementation.

I'd be mildly in favor of doing this, but we have mentioned tradeoffs in
this thread.

So do we want to do this or not?

Without having reviewed the patch yet, yes, I'd say we want this.

Greetings,

Andres Freund

#27Andres Freund
andres@anarazel.de
In reply to: Peter Eisentraut (#22)
Re: transction_timestamp() inside of procedures

On 2018-09-28 09:35:48 +0200, Peter Eisentraut wrote:

On 26/09/2018 23:48, Peter Eisentraut wrote:

That's certainly a good argument. Note that if we implemented that the
transaction timestamp is advanced inside procedures, that would also
mean that the transaction timestamp as observed in pg_stat_activity
would move during VACUUM, for example. That might or might not be
desirable.

I think it doesn't hurt, although it's also not a huge advantage.

diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index 9aa63c8792..245735420c 100644
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -1884,14 +1884,19 @@ StartTransaction(void)
TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId);
/*
-	 * set transaction_timestamp() (a/k/a now()).  We want this to be the same
-	 * as the first command's statement_timestamp(), so don't do a fresh
-	 * GetCurrentTimestamp() call (which'd be expensive anyway).  Also, mark
-	 * xactStopTimestamp as unset.
-	 */
-	xactStartTimestamp = stmtStartTimestamp;
-	xactStopTimestamp = 0;
+	 * set transaction_timestamp() (a/k/a now()).  Normally, we want this to
+	 * be the same as the first command's statement_timestamp(), so don't do a
+	 * fresh GetCurrentTimestamp() call (which'd be expensive anyway).  But
+	 * for transactions started inside statements (e.g., procedure calls), we
+	 * want to advance the timestamp.
+	 */
+	if (xactStartTimestamp < stmtStartTimestamp)
+		xactStartTimestamp = stmtStartTimestamp;
+	else
+		xactStartTimestamp = GetCurrentTimestamp();
pgstat_report_xact_timestamp(xactStartTimestamp);
+	/* Mark xactStopTimestamp as unset. */
+	xactStopTimestamp = 0;

It's a bit weird to make this decision based on these two timestamps
differing. For one, it only indirectly seems to be guaranteed that
xactStartTimestamp is even set to anything here (to 0 by virtue of being
a global var).

Greetings,

Andres Freund

#28Merlin Moncure
mmoncure@gmail.com
In reply to: Alvaro Herrera (#18)
Re: transction_timestamp() inside of procedures

On Wed, Sep 26, 2018 at 10:55 AM Alvaro Herrera
<alvherre@2ndquadrant.com> wrote:

On 2018-Sep-26, Tom Lane wrote:

Alvaro Herrera <alvherre@2ndquadrant.com> writes:

On 2018-Sep-26, Tom Lane wrote:

I agree that it would be surprising for transaction timestamp to be newer
than statement timestamp. So for now at least, I'd be satisfied with
documenting the behavior.

Really? I thought it was practically obvious that for transaction-
controlling procedures, the transaction timestamp would not necessarily
be aligned with the statement timestamp. The surprise would come
together with the usage of the new feature, so existing users would not
be surprised in any way.

Nope. That's the same poor reasoning we've fallen into in some other
cases, of assuming that "the user" is a point source of knowledge.
But DBMSes tend to interact with lots of different code. If some part
of application A starts using intraprocedure transactions, and then
application B breaks because it wasn't expecting to see xact_start
later than query_start in pg_stat_activity, you've still got a problem.

While that's true, I think it's also highly hypothetical.

What could be the use for the transaction timestamp? I think one of the
most important uses (at least in pg_stat_activity) is to verify that
transactions are not taking excessively long time to complete;

+1

I think the existing behavior is broken, and extremely so.
Transaction timestamp has a very clear definition to me. I'm in
planning to move a lot of code into stored procedures from bash, and
upon doing so it's going to trip all kinds of nagios alarms that are
looking at the longest running transaction.

merlin

#29Peter Eisentraut
peter.eisentraut@2ndquadrant.com
In reply to: Andres Freund (#27)
1 attachment(s)
Re: transction_timestamp() inside of procedures

On 02/10/2018 16:58, Andres Freund wrote:

It's a bit weird to make this decision based on these two timestamps
differing. For one, it only indirectly seems to be guaranteed that
xactStartTimestamp is even set to anything here (to 0 by virtue of being
a global var).

Maybe but it seems to be the simplest way without doing major surgery to
all this code.

Attached is an updated patch with a test case.

--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Attachments:

v2-0001-Advance-transaction-timestamp-in-intra-procedure-.patchtext/plain; charset=UTF-8; name=v2-0001-Advance-transaction-timestamp-in-intra-procedure-.patch; x-mac-creator=0; x-mac-type=0Download
From a7b7c4094a54f9b217332809b1abfb521a4b994d Mon Sep 17 00:00:00 2001
From: Peter Eisentraut <peter_e@gmx.net>
Date: Fri, 5 Oct 2018 12:24:34 +0200
Subject: [PATCH v2] Advance transaction timestamp in intra-procedure
 transactions

---
 src/backend/access/transam/xact.c             | 19 +++++++-----
 .../src/expected/plpgsql_transaction.out      | 28 +++++++++++++++++
 .../plpgsql/src/sql/plpgsql_transaction.sql   | 31 +++++++++++++++++++
 3 files changed, 71 insertions(+), 7 deletions(-)

diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index 9aa63c8792..245735420c 100644
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -1884,14 +1884,19 @@ StartTransaction(void)
 	TRACE_POSTGRESQL_TRANSACTION_START(vxid.localTransactionId);
 
 	/*
-	 * set transaction_timestamp() (a/k/a now()).  We want this to be the same
-	 * as the first command's statement_timestamp(), so don't do a fresh
-	 * GetCurrentTimestamp() call (which'd be expensive anyway).  Also, mark
-	 * xactStopTimestamp as unset.
-	 */
-	xactStartTimestamp = stmtStartTimestamp;
-	xactStopTimestamp = 0;
+	 * set transaction_timestamp() (a/k/a now()).  Normally, we want this to
+	 * be the same as the first command's statement_timestamp(), so don't do a
+	 * fresh GetCurrentTimestamp() call (which'd be expensive anyway).  But
+	 * for transactions started inside statements (e.g., procedure calls), we
+	 * want to advance the timestamp.
+	 */
+	if (xactStartTimestamp < stmtStartTimestamp)
+		xactStartTimestamp = stmtStartTimestamp;
+	else
+		xactStartTimestamp = GetCurrentTimestamp();
 	pgstat_report_xact_timestamp(xactStartTimestamp);
+	/* Mark xactStopTimestamp as unset. */
+	xactStopTimestamp = 0;
 
 	/*
 	 * initialize current transaction state fields
diff --git a/src/pl/plpgsql/src/expected/plpgsql_transaction.out b/src/pl/plpgsql/src/expected/plpgsql_transaction.out
index 77a83adab5..71e56300bc 100644
--- a/src/pl/plpgsql/src/expected/plpgsql_transaction.out
+++ b/src/pl/plpgsql/src/expected/plpgsql_transaction.out
@@ -493,6 +493,34 @@ CALL transaction_test10b(10);
  9
 (1 row)
 
+-- transaction timestamp vs. statement timestamp
+CREATE PROCEDURE transaction_test11()
+LANGUAGE plpgsql
+AS $$
+DECLARE
+  s1 timestamp with time zone;
+  s2 timestamp with time zone;
+  s3 timestamp with time zone;
+  t1 timestamp with time zone;
+  t2 timestamp with time zone;
+  t3 timestamp with time zone;
+BEGIN
+  s1 := statement_timestamp();
+  t1 := transaction_timestamp();
+  ASSERT s1 = t1;
+  COMMIT;
+  s2 := statement_timestamp();
+  t2 := transaction_timestamp();
+  ASSERT s2 = s1;
+  ASSERT t2 > t1;
+  ROLLBACK;
+  s3 := statement_timestamp();
+  t3 := transaction_timestamp();
+  ASSERT s3 = s1;
+  ASSERT t3 > t2;
+END;
+$$;
+CALL transaction_test11();
 DROP TABLE test1;
 DROP TABLE test2;
 DROP TABLE test3;
diff --git a/src/pl/plpgsql/src/sql/plpgsql_transaction.sql b/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
index 0ed9ab873a..e2089f56ad 100644
--- a/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
+++ b/src/pl/plpgsql/src/sql/plpgsql_transaction.sql
@@ -412,6 +412,37 @@ CREATE PROCEDURE transaction_test10b(INOUT x int)
 CALL transaction_test10b(10);
 
 
+-- transaction timestamp vs. statement timestamp
+CREATE PROCEDURE transaction_test11()
+LANGUAGE plpgsql
+AS $$
+DECLARE
+  s1 timestamp with time zone;
+  s2 timestamp with time zone;
+  s3 timestamp with time zone;
+  t1 timestamp with time zone;
+  t2 timestamp with time zone;
+  t3 timestamp with time zone;
+BEGIN
+  s1 := statement_timestamp();
+  t1 := transaction_timestamp();
+  ASSERT s1 = t1;
+  COMMIT;
+  s2 := statement_timestamp();
+  t2 := transaction_timestamp();
+  ASSERT s2 = s1;
+  ASSERT t2 > t1;
+  ROLLBACK;
+  s3 := statement_timestamp();
+  t3 := transaction_timestamp();
+  ASSERT s3 = s1;
+  ASSERT t3 > t2;
+END;
+$$;
+
+CALL transaction_test11();
+
+
 DROP TABLE test1;
 DROP TABLE test2;
 DROP TABLE test3;

base-commit: ff347f8aff04865680c19ffc818460bb2afaad5b
-- 
2.19.0

#30Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Eisentraut (#29)
Re: transction_timestamp() inside of procedures

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:

On 02/10/2018 16:58, Andres Freund wrote:

It's a bit weird to make this decision based on these two timestamps
differing. For one, it only indirectly seems to be guaranteed that
xactStartTimestamp is even set to anything here (to 0 by virtue of being
a global var).

Maybe but it seems to be the simplest way without doing major surgery to
all this code.

This patch doesn't apply over 07ee62ce9. Also, I like the
timestamp-comparison approach even less than Andres does: I think it's
probably outright broken, especially since it treats the equality case
as license to advance xactStartTimestamp.

Surely there is some way that we can directly test whether we're inside a
procedure or not? I think the logic should be basically

    if (!IsParallelWorker())
+   {
+       if (!InsideProcedure())
            xactStartTimestamp = stmtStartTimestamp;
+       else
+           xactStartTimestamp = GetCurrentTimestamp();
+   }
    else
       Assert(xactStartTimestamp != 0);

regards, tom lane

#31Andres Freund
andres@anarazel.de
In reply to: Tom Lane (#30)
Re: transction_timestamp() inside of procedures

Hi,

On October 8, 2018 10:14:34 AM PDT, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Peter Eisentraut <peter.eisentraut@2ndquadrant.com> writes:

On 02/10/2018 16:58, Andres Freund wrote:

It's a bit weird to make this decision based on these two timestamps
differing. For one, it only indirectly seems to be guaranteed that
xactStartTimestamp is even set to anything here (to 0 by virtue of

being

a global var).

Maybe but it seems to be the simplest way without doing major surgery

to

all this code.

This patch doesn't apply over 07ee62ce9. Also, I like the
timestamp-comparison approach even less than Andres does: I think it's
probably outright broken, especially since it treats the equality case
as license to advance xactStartTimestamp.

Surely there is some way that we can directly test whether we're inside
a
procedure or not? I think the logic should be basically

if (!IsParallelWorker())
+   {
+       if (!InsideProcedure())
xactStartTimestamp = stmtStartTimestamp;
+       else
+           xactStartTimestamp = GetCurrentTimestamp();
+   }
else
Assert(xactStartTimestamp != 0);

Seems more reasonable from here.

Andres
--
Sent from my Android device with K-9 Mail. Please excuse my brevity.

#32Tom Lane
tgl@sss.pgh.pa.us
In reply to: Andres Freund (#31)
Re: transction_timestamp() inside of procedures

Andres Freund <andres@anarazel.de> writes:

On October 8, 2018 10:14:34 AM PDT, Tom Lane <tgl@sss.pgh.pa.us> wrote:

Surely there is some way that we can directly test whether we're inside
a procedure or not? I think the logic should be basically
...

Seems more reasonable from here.

We are rapidly running out of time to get this fixed before RC1.
In the interests of getting across the finish line, I took a look
around, and found that indeed there does not seem to be any exported
way to detect whether we're inside a procedure or not. Which seems
pretty darn dumb from here.

The best way to determine that seems to be to check that that the SPI
stack is (a) nonempty and (b) has a "nonatomic" topmost entry.

Barring objections, I'm going to make a quick hack that adds a SPI
entry point along the lines of "bool SPI_inside_nonatomic_context(void)"
to do that test, adapt the xact.c code as I said upthread, and commit
with Peter's regression test case.

regards, tom lane