Thread: Problem with background worker
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 logVALUES (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+012013-03-20 15:01:44.618623+01 | 2013-03-2015:01:44.618623+01 | 2013-03-20 15:01:53.784301+012013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01| 2013-03-20 15:01:54.834212+012013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-2015:01:55.848497+012013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:56.872671+012013-03-2015:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:57.888461+012013-03-2015:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:58.912448+012013-03-2015:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:01:59.936335+012013-03-2015:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:02:00.951247+012013-03-2015:01:44.618623+01 | 2013-03-20 15:01:44.618623+01 | 2013-03-20 15:02:01.967937+012013-03-2015: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
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
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
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
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
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