Problem with background worker

Started by Marc Cousinalmost 13 years ago6 messages
#1Marc Cousin
cousinmarc@gmail.com

Hi,

I'm trying to write a background writer, and I'm facing a problem with
timestamps. The following code is where I'm having a problem (it's just a demo for
the problem):

BackgroundWorkerInitializeConnection("test", NULL);
while (!got_sigterm)
{
int ret;
/* Wait 1s */
ret = WaitLatch(&MyProc->procLatch,
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
1000L);
ResetLatch(&MyProc->procLatch);
/* Insert dummy for now */
StartTransactionCommand();
SPI_connect();
PushActiveSnapshot(GetTransactionSnapshot());
ret = SPI_execute("INSERT INTO log VALUES (now(),statement_timestamp(),clock_timestamp())", false, 0);
SPI_finish();
PopActiveSnapshot();
CommitTransactionCommand();
}

\d log

Column | Type | Modifiers
---------------------+--------------------------+---------------
now | timestamp with time zone |
statement_timestamp | timestamp with time zone |
clock_timestamp | timestamp with time zone |

Here is its content. Only the clock_timestamp is right. There are missing records at the
beginning because i truncated the table for this example.

now | statement_timestamp | clock_timestamp
-------------------------------+-------------------------------+-------------------------------
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:52.77683+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:53.784301+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:54.834212+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:55.848497+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:56.872671+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:57.888461+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:58.912448+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:59.936335+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:02:00.951247+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:02:01.967937+01
2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:02:02.983613+01

Most of the code is copy/paste from worker_spi (I don't really understand the
PushActiveSnapshot(GetTransactionSnapshot()) and PopActiveSnapshot() but the
behaviour is the same with or without them, and they were in worker_spi).

I guess I'm doing something wrong, but I really dont't know what it is.

Should I attach the whole code ?

Regards,

Marc

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#2Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Marc Cousin (#1)
Re: Problem with background worker

Marc Cousin escribió:

Hi,

I'm trying to write a background writer, and I'm facing a problem with
timestamps. The following code is where I'm having a problem (it's just a demo for
the problem):

BackgroundWorkerInitializeConnection("test", NULL);
while (!got_sigterm)
{
int ret;
/* Wait 1s */
ret = WaitLatch(&MyProc->procLatch,
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
1000L);
ResetLatch(&MyProc->procLatch);
/* Insert dummy for now */
StartTransactionCommand();
SPI_connect();
PushActiveSnapshot(GetTransactionSnapshot());
ret = SPI_execute("INSERT INTO log VALUES (now(),statement_timestamp(),clock_timestamp())", false, 0);
SPI_finish();
PopActiveSnapshot();
CommitTransactionCommand();
}

Ah. The reason for this problem is that the statement start time (which
also sets the transaction start time, when it's the first statement) is
set by postgres.c, not the transaction-control functions in xact.c. So
you'd need to add a SetCurrentStatementStartTimestamp() call somewhere
in your loop.

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#3Marc Cousin
cousinmarc@gmail.com
In reply to: Alvaro Herrera (#2)
Re: Problem with background worker

On 20/03/2013 16:33, Alvaro Herrera wrote:

Marc Cousin escribió:

Hi,

I'm trying to write a background writer, and I'm facing a problem with
timestamps. The following code is where I'm having a problem (it's just a demo for
the problem):

BackgroundWorkerInitializeConnection("test", NULL);
while (!got_sigterm)
{
int ret;
/* Wait 1s */
ret = WaitLatch(&MyProc->procLatch,
WL_LATCH_SET | WL_TIMEOUT | WL_POSTMASTER_DEATH,
1000L);
ResetLatch(&MyProc->procLatch);
/* Insert dummy for now */
StartTransactionCommand();
SPI_connect();
PushActiveSnapshot(GetTransactionSnapshot());
ret = SPI_execute("INSERT INTO log VALUES (now(),statement_timestamp(),clock_timestamp())", false, 0);
SPI_finish();
PopActiveSnapshot();
CommitTransactionCommand();
}

Ah. The reason for this problem is that the statement start time (which
also sets the transaction start time, when it's the first statement) is
set by postgres.c, not the transaction-control functions in xact.c. So
you'd need to add a SetCurrentStatementStartTimestamp() call somewhere
in your loop.

Yes, that works. Thanks a lot !

Maybe this should be added to the worker_spi example ?

Regards

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#4Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Marc Cousin (#3)
Re: Problem with background worker

Marc Cousin escribió:

On 20/03/2013 16:33, Alvaro Herrera wrote:

Ah. The reason for this problem is that the statement start time (which
also sets the transaction start time, when it's the first statement) is
set by postgres.c, not the transaction-control functions in xact.c. So
you'd need to add a SetCurrentStatementStartTimestamp() call somewhere
in your loop.

Yes, that works. Thanks a lot !

Maybe this should be added to the worker_spi example ?

Yeah, I think I need to go over the postgres.c code and figure out what
else needs to be called. I have a pending patch from Guillaume to
improve worker_spi some more; I'll add this bit too.

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#5Guillaume Lelarge
guillaume@lelarge.info
In reply to: Alvaro Herrera (#4)
Re: Problem with background worker

On Wed, 2013-03-20 at 13:13 -0300, Alvaro Herrera wrote:

Marc Cousin escribió:

On 20/03/2013 16:33, Alvaro Herrera wrote:

Ah. The reason for this problem is that the statement start time (which
also sets the transaction start time, when it's the first statement) is
set by postgres.c, not the transaction-control functions in xact.c. So
you'd need to add a SetCurrentStatementStartTimestamp() call somewhere
in your loop.

Yes, that works. Thanks a lot !

Maybe this should be added to the worker_spi example ?

Yeah, I think I need to go over the postgres.c code and figure out what
else needs to be called. I have a pending patch from Guillaume to
improve worker_spi some more; I'll add this bit too.

Happy to know that you still remember it :) Thanks.

--
Guillaume
http://blog.guillaume.lelarge.info
http://www.dalibo.com

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

#6Alvaro Herrera
alvherre@2ndquadrant.com
In reply to: Marc Cousin (#3)
Re: Problem with background worker

Marc Cousin escribió:

On 20/03/2013 16:33, Alvaro Herrera wrote:

Ah. The reason for this problem is that the statement start time (which
also sets the transaction start time, when it's the first statement) is
set by postgres.c, not the transaction-control functions in xact.c. So
you'd need to add a SetCurrentStatementStartTimestamp() call somewhere
in your loop.

Yes, that works. Thanks a lot !

Maybe this should be added to the worker_spi example ?

Done in
http://git.postgresql.org/pg/commitdiff/e543631f3c162ab5f6020b1d0209e0353ca2229a

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

--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers