pgsql: Write a WAL record whenever we perform an operation without
Log Message:
-----------
Write a WAL record whenever we perform an operation without WAL-logging
that would've been WAL-logged if archiving was enabled. If we encounter
such records in archive recovery anyway, we know that some data is
missing from the log. A WARNING is emitted in that case.
Original patch by Fujii Masao, with changes by me.
Modified Files:
--------------
pgsql/src/backend/access/heap:
heapam.c (r1.282 -> r1.283)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/heap/heapam.c?r1=1.282&r2=1.283)
pgsql/src/backend/access/nbtree:
nbtsort.c (r1.122 -> r1.123)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/nbtree/nbtsort.c?r1=1.122&r2=1.123)
pgsql/src/backend/access/transam:
xlog.c (r1.358 -> r1.359)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/transam/xlog.c?r1=1.358&r2=1.359)
pgsql/src/backend/commands:
cluster.c (r1.193 -> r1.194)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/commands/cluster.c?r1=1.193&r2=1.194)
tablecmds.c (r1.316 -> r1.317)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/commands/tablecmds.c?r1=1.316&r2=1.317)
pgsql/src/include/access:
xlog.h (r1.97 -> r1.98)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/include/access/xlog.h?r1=1.97&r2=1.98)
pgsql/src/include/catalog:
pg_control.h (r1.48 -> r1.49)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/include/catalog/pg_control.h?r1=1.48&r2=1.49)
On Wed, Jan 20, 2010 at 2:43 PM, Heikki Linnakangas
<heikki@postgresql.org> wrote:
Log Message:
-----------
Write a WAL record whenever we perform an operation without WAL-logging
that would've been WAL-logged if archiving was enabled. If we encounter
such records in archive recovery anyway, we know that some data is
missing from the log. A WARNING is emitted in that case.Original patch by Fujii Masao, with changes by me.
Does this need to be updated, then?
https://commitfest.postgresql.org/action/patch_view?id=237
...Robert
Robert Haas <robertmhaas@gmail.com> wrote:
Does this need to be updated, then?
https://commitfest.postgresql.org/action/patch_view?id=237
I updated it.
Regards,
---
Takahiro Itagaki
NTT Open Source Software Center
I'm seeing these messages in the standby server log:
WARNING: unlogged operation performed, data may be missing
HINT: This can happen if you temporarily disable archive_mode without
taking a new base backup.
CONTEXT: xlog redo unlogged operation: heap inserts on "pg_temp_65646"
which connected with operations on temp tables, probably as a result of
VACUUM FULL and CLUSTER.
I don't think those messages should be there.
On Wed, 2010-01-20 at 19:43 +0000, Heikki Linnakangas wrote:
Log Message:
-----------
Write a WAL record whenever we perform an operation without WAL-logging
that would've been WAL-logged if archiving was enabled. If we encounter
such records in archive recovery anyway, we know that some data is
missing from the log. A WARNING is emitted in that case.Original patch by Fujii Masao, with changes by me.
Modified Files:
--------------
pgsql/src/backend/access/heap:
heapam.c (r1.282 -> r1.283)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/heap/heapam.c?r1=1.282&r2=1.283)
pgsql/src/backend/access/nbtree:
nbtsort.c (r1.122 -> r1.123)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/nbtree/nbtsort.c?r1=1.122&r2=1.123)
pgsql/src/backend/access/transam:
xlog.c (r1.358 -> r1.359)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/access/transam/xlog.c?r1=1.358&r2=1.359)
pgsql/src/backend/commands:
cluster.c (r1.193 -> r1.194)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/commands/cluster.c?r1=1.193&r2=1.194)
tablecmds.c (r1.316 -> r1.317)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/backend/commands/tablecmds.c?r1=1.316&r2=1.317)
pgsql/src/include/access:
xlog.h (r1.97 -> r1.98)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/include/access/xlog.h?r1=1.97&r2=1.98)
pgsql/src/include/catalog:
pg_control.h (r1.48 -> r1.49)
(http://anoncvs.postgresql.org/cvsweb.cgi/pgsql/src/include/catalog/pg_control.h?r1=1.48&r2=1.49)
--
Simon Riggs www.2ndQuadrant.com
Simon Riggs wrote:
I'm seeing these messages in the standby server log:
WARNING: unlogged operation performed, data may be missing
HINT: This can happen if you temporarily disable archive_mode without
taking a new base backup.
CONTEXT: xlog redo unlogged operation: heap inserts on "pg_temp_65646"which connected with operations on temp tables, probably as a result of
VACUUM FULL and CLUSTER.I don't think those messages should be there.
Hmm. The "unlogged" record is written here:
...
void
heap_sync(Relation rel)
{
char reason[NAMEDATALEN + 30];
/* temp tables never need fsync */
if (rel->rd_istemp)
return;
snprintf(reason, sizeof(reason), "heap inserts on \"%s\"",
RelationGetRelationName(rel));
XLogReportUnloggedStatement(reason);
...
So it clearly shouldn't be written for temp relations. Apparently the
rd_istemp flag not set correctly after CLUSTER / VACUUM FULL.
Can you reproduce that?
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
--
Simon Riggs www.2ndQuadrant.com
On Mon, Feb 1, 2010 at 6:33 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:
Hmm. The "unlogged" record is written here:
...
void
heap_sync(Relation rel)
{
char reason[NAMEDATALEN + 30];/* temp tables never need fsync */
if (rel->rd_istemp)
return;snprintf(reason, sizeof(reason), "heap inserts on \"%s\"",
RelationGetRelationName(rel));
XLogReportUnloggedStatement(reason);
...So it clearly shouldn't be written for temp relations. Apparently the
rd_istemp flag not set correctly after CLUSTER / VACUUM FULL.
The cause of the problem seems to be the new heap created by
rebuild_relation() and copy_heap_data(), i.e., new VACUUM FULL.
Since it's not a temporary heap, its rd_istemp is off. OTOH
it needs to be synced after physical copy from old heap. So
XLogReportUnloggedStatement() is called in heap_sync().
The easy fix is to change the code as below.
if (XLogIsNeeded())
{
snprintf(reason, sizeof(reason), "heap inserts on \"%s\"",
RelationGetRelationName(rel));
XLogReportUnloggedStatement(reason);
}
But I'm not sure this fix is right, so I need to investigate
the code more.
Regards,
--
Fujii Masao
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center
Simon Riggs wrote:
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
Ok, good :-). What I really meant was: How?
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
On Mon, 2010-02-01 at 12:11 +0200, Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
Ok, good :-). What I really meant was: How?
As mentioned in first post: VACUUM FULL and CLUSTER.
Coffee is recommended.
--
Simon Riggs www.2ndQuadrant.com
On Mon, Feb 1, 2010 at 6:58 PM, Fujii Masao <masao.fujii@gmail.com> wrote:
if (XLogIsNeeded())
{
snprintf(reason, sizeof(reason), "heap inserts on \"%s\"",
RelationGetRelationName(rel));
XLogReportUnloggedStatement(reason);
}
Oops!
Typo: XLogIsNeeded() --> !XLogIsNeeded()
Regards,
--
Fujii Masao
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center
Fujii Masao wrote:
The cause of the problem seems to be the new heap created by
rebuild_relation() and copy_heap_data(), i.e., new VACUUM FULL.
Since it's not a temporary heap, its rd_istemp is off. OTOH
it needs to be synced after physical copy from old heap.
Why does it need to be synced?
ISTM the bug is that rd_istemp is off at that point.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
Simon Riggs wrote:
On Mon, 2010-02-01 at 12:11 +0200, Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
Ok, good :-). What I really meant was: How?
As mentioned in first post: VACUUM FULL and CLUSTER.
I'm asking because I couldn't reproduce it. I added an elog(LOG) to
XLogReportUnloggedStatement() so that I can see when an unlogged-record
is written. Then I ran:
CREATE TEMPORARY TABLE foo (id int4);
VACUUM FULL foo;
But XLogReportUnloggedStatement() was not executed. When I removed the
"TEMPORARY" and tried again, it was executed.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
On Mon, Feb 1, 2010 at 7:27 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:
Fujii Masao wrote:
The cause of the problem seems to be the new heap created by
rebuild_relation() and copy_heap_data(), i.e., new VACUUM FULL.
Since it's not a temporary heap, its rd_istemp is off. OTOH
it needs to be synced after physical copy from old heap.Why does it need to be synced?
ISTM the bug is that rd_istemp is off at that point.
Umm... ISTM that new heap needs to be synced before calling
swap_relation_files(), but, in the now, I'm not sure whether
it's really required or not. Sorry.
Regards,
--
Fujii Masao
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center
On Mon, Feb 1, 2010 at 7:30 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:
CREATE TEMPORARY TABLE foo (id int4);
VACUUM FULL foo;
How about issuing just "VACUUM FULL" after creating log-shipping environment?
Regards,
--
Fujii Masao
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center
Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 12:11 +0200, Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
Ok, good :-). What I really meant was: How?
As mentioned in first post: VACUUM FULL and CLUSTER.
I'm asking because I couldn't reproduce it. I added an elog(LOG) to
XLogReportUnloggedStatement() so that I can see when an unlogged-record
is written. Then I ran:CREATE TEMPORARY TABLE foo (id int4);
VACUUM FULL foo;But XLogReportUnloggedStatement() was not executed. When I removed the
"TEMPORARY" and tried again, it was executed.
No, hang on. When I run this:
postgres=# CREATE TABLE foo (id int4);
CREATE TABLE
postgres=# vacuum full foo;
VACUUM
I get this in the log:
LOG: Writing record: CLUSTER on "pg_temp_24677"
STATEMENT: vacuum full foo;
LOG: Writing record: heap inserts on "pg_temp_24677"
STATEMENT: vacuum full foo;
So you get those messages when the table is *not* a temporary table. I
can see now what Fujii was trying to say. His patch seems Ok, though
perhaps it would be better to move the responsibility of calling
XLogReportUnloggedStatement() to the callers of heap_sync(). When I put
it in heap_sync(), I didn't take into account that it's sometimes called
just to flush buffers from buffer cache, not to fsync() non-WAL-logged
operations.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
On Mon, 2010-02-01 at 12:30 +0200, Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 12:11 +0200, Heikki Linnakangas wrote:
Simon Riggs wrote:
On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
Can you reproduce that?
Every time
Ok, good :-). What I really meant was: How?
As mentioned in first post: VACUUM FULL and CLUSTER.
I'm asking because I couldn't reproduce it. I added an elog(LOG) to
XLogReportUnloggedStatement() so that I can see when an unlogged-record
is written. Then I ran:CREATE TEMPORARY TABLE foo (id int4);
VACUUM FULL foo;But XLogReportUnloggedStatement() was not executed. When I removed the
"TEMPORARY" and tried again, it was executed.
drop table if exists foo;
create table foo (col1 serial, col2 text);
insert into foo (col2)
select repeat('a', 5000) from generate_series(1,1000);
create index on foo (col1);
cluster foo using foo_col1_idx;
So it appears this relates to toast tables.
--
Simon Riggs www.2ndQuadrant.com
Fujii Masao <masao.fujii@gmail.com> writes:
On Mon, Feb 1, 2010 at 7:27 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:Fujii Masao wrote:
The cause of the problem seems to be the new heap created by
rebuild_relation() and copy_heap_data(), i.e., new VACUUM FULL.
Since it's not a temporary heap, its rd_istemp is off. OTOH
it needs to be synced after physical copy from old heap.Why does it need to be synced?
ISTM the bug is that rd_istemp is off at that point.
Umm... ISTM that new heap needs to be synced before calling
swap_relation_files(), but, in the now, I'm not sure whether
it's really required or not. Sorry.
If the original table is temp, then none of this work needs to be
fsync'd. Ever. So ISTM that CLUSTER ought to be copying the istemp
bit. Another reason to do that is to make sure that the new instance
of the table goes into the temp tablespace and not the regular one.
regards, tom lane
On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:
So you get those messages when the table is *not* a temporary table. I
can see now what Fujii was trying to say. His patch seems Ok, though
perhaps it would be better to move the responsibility of calling
XLogReportUnloggedStatement() to the callers of heap_sync(). When I put
it in heap_sync(), I didn't take into account that it's sometimes called
just to flush buffers from buffer cache, not to fsync() non-WAL-logged
operations.
As you said, I moved the responsibility of calling XLogReportUnloggedStatement()
to the callers of heap_sync(). Here is the patch.
Regards,
--
Fujii Masao
NIPPON TELEGRAPH AND TELEPHONE CORPORATION
NTT Open Source Software Center
Attachments:
unlogged_operation_by_vacuum_full_20100202.patchtext/x-patch; charset=US-ASCII; name=unlogged_operation_by_vacuum_full_20100202.patchDownload
*** a/src/backend/access/heap/heapam.c
--- b/src/backend/access/heap/heapam.c
***************
*** 5074,5089 **** heap2_desc(StringInfo buf, uint8 xl_info, char *rec)
void
heap_sync(Relation rel)
{
- char reason[NAMEDATALEN + 30];
-
/* temp tables never need fsync */
if (rel->rd_istemp)
return;
- snprintf(reason, sizeof(reason), "heap inserts on \"%s\"",
- RelationGetRelationName(rel));
- XLogReportUnloggedStatement(reason);
-
/* main heap */
FlushRelationBuffers(rel);
/* FlushRelationBuffers will have opened rd_smgr */
--- 5074,5083 ----
*** a/src/backend/access/heap/rewriteheap.c
--- b/src/backend/access/heap/rewriteheap.c
***************
*** 246,252 **** begin_heap_rewrite(Relation new_heap, TransactionId oldest_xmin,
* state and any other resources are freed.
*/
void
! end_heap_rewrite(RewriteState state)
{
HASH_SEQ_STATUS seq_status;
UnresolvedTup unresolved;
--- 246,252 ----
* state and any other resources are freed.
*/
void
! end_heap_rewrite(RewriteState state, bool use_wal)
{
HASH_SEQ_STATUS seq_status;
UnresolvedTup unresolved;
***************
*** 278,283 **** end_heap_rewrite(RewriteState state)
--- 278,292 ----
(char *) state->rs_buffer, true);
}
+ /* Write an XLOG UNLOGGED record if WAL-logging was skipped */
+ if (!use_wal && !state->rs_new_rel->rd_istemp)
+ {
+ char reason[NAMEDATALEN + 30];
+ snprintf(reason, sizeof(reason), "heap rewrite on \"%s\"",
+ RelationGetRelationName(state->rs_new_rel));
+ XLogReportUnloggedStatement(reason);
+ }
+
/*
* If the rel isn't temp, must fsync before commit. We use heap_sync to
* ensure that the toast table gets fsync'd too.
*** a/src/backend/commands/cluster.c
--- b/src/backend/commands/cluster.c
***************
*** 998,1004 **** copy_heap_data(Oid OIDNewHeap, Oid OIDOldHeap, Oid OIDOldIndex,
heap_endscan(heapScan);
/* Write out any remaining tuples, and fsync if needed */
! end_heap_rewrite(rwstate);
pfree(values);
pfree(isnull);
--- 998,1004 ----
heap_endscan(heapScan);
/* Write out any remaining tuples, and fsync if needed */
! end_heap_rewrite(rwstate, use_wal);
pfree(values);
pfree(isnull);
*** a/src/backend/commands/copy.c
--- b/src/backend/commands/copy.c
***************
*** 2225,2231 **** CopyFrom(CopyState cstate)
--- 2225,2237 ----
* indexes since those use WAL anyway)
*/
if (hi_options & HEAP_INSERT_SKIP_WAL)
+ {
+ char reason[NAMEDATALEN + 30];
+ snprintf(reason, sizeof(reason), "COPY FROM on \"%s\"",
+ RelationGetRelationName(cstate->rel));
+ XLogReportUnloggedStatement(reason);
heap_sync(cstate->rel);
+ }
}
*** a/src/backend/commands/tablecmds.c
--- b/src/backend/commands/tablecmds.c
***************
*** 3297,3303 **** ATRewriteTable(AlteredTableInfo *tab, Oid OIDNewHeap)
--- 3297,3309 ----
/* If we skipped writing WAL, then we need to sync the heap. */
if (hi_options & HEAP_INSERT_SKIP_WAL)
+ {
+ char reason[NAMEDATALEN + 30];
+ snprintf(reason, sizeof(reason), "table rewrite on \"%s\"",
+ RelationGetRelationName(newrel));
+ XLogReportUnloggedStatement(reason);
heap_sync(newrel);
+ }
heap_close(newrel, NoLock);
}
*** a/src/backend/executor/execMain.c
--- b/src/backend/executor/execMain.c
***************
*** 2240,2246 **** CloseIntoRel(QueryDesc *queryDesc)
--- 2240,2252 ----
/* If we skipped using WAL, must heap_sync before commit */
if (myState->hi_options & HEAP_INSERT_SKIP_WAL)
+ {
+ char reason[NAMEDATALEN + 30];
+ snprintf(reason, sizeof(reason), "SELECT INTO on \"%s\"",
+ RelationGetRelationName(myState->rel));
+ XLogReportUnloggedStatement(reason);
heap_sync(myState->rel);
+ }
/* close rel, but keep lock until commit */
heap_close(myState->rel, NoLock);
*** a/src/include/access/rewriteheap.h
--- b/src/include/access/rewriteheap.h
***************
*** 22,28 **** typedef struct RewriteStateData *RewriteState;
extern RewriteState begin_heap_rewrite(Relation NewHeap,
TransactionId OldestXmin, TransactionId FreezeXid,
bool use_wal);
! extern void end_heap_rewrite(RewriteState state);
extern void rewrite_heap_tuple(RewriteState state, HeapTuple oldTuple,
HeapTuple newTuple);
extern void rewrite_heap_dead_tuple(RewriteState state, HeapTuple oldTuple);
--- 22,28 ----
extern RewriteState begin_heap_rewrite(Relation NewHeap,
TransactionId OldestXmin, TransactionId FreezeXid,
bool use_wal);
! extern void end_heap_rewrite(RewriteState state, bool use_wal);
extern void rewrite_heap_tuple(RewriteState state, HeapTuple oldTuple,
HeapTuple newTuple);
extern void rewrite_heap_dead_tuple(RewriteState state, HeapTuple oldTuple);
Fujii Masao wrote:
On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:So you get those messages when the table is *not* a temporary table. I
can see now what Fujii was trying to say. His patch seems Ok, though
perhaps it would be better to move the responsibility of calling
XLogReportUnloggedStatement() to the callers of heap_sync(). When I put
it in heap_sync(), I didn't take into account that it's sometimes called
just to flush buffers from buffer cache, not to fsync() non-WAL-logged
operations.As you said, I moved the responsibility of calling XLogReportUnloggedStatement()
to the callers of heap_sync(). Here is the patch.
Committed. The use_wal parameter to end_heap_rewrite() was not
necessary, that information is already in RewriteState, so I took that out.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com
Fujii Masao wrote:
On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:So you get those messages when the table is *not* a temporary table. I
can see now what Fujii was trying to say. His patch seems Ok, though
perhaps it would be better to move the responsibility of calling
XLogReportUnloggedStatement() to the callers of heap_sync(). When I put
it in heap_sync(), I didn't take into account that it's sometimes called
just to flush buffers from buffer cache, not to fsync() non-WAL-logged
operations.As you said, I moved the responsibility of calling XLogReportUnloggedStatement()
to the callers of heap_sync(). Here is the patch.Committed. The use_wal parameter to end_heap_rewrite() was not
necessary, that information is already in RewriteState, so I took that out.
Are we going to bump up frontend/backend protocol version 3.0 to 3.x
or some such?
--
Tatsuo Ishii
SRA OSS, Inc. Japan
English: http://www.sraoss.co.jp/index_en.php
Japanese: http://www.sraoss.co.jp
Tatsuo Ishii wrote:
Fujii Masao wrote:
On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
<heikki.linnakangas@enterprisedb.com> wrote:So you get those messages when the table is *not* a temporary table. I
can see now what Fujii was trying to say. His patch seems Ok, though
perhaps it would be better to move the responsibility of calling
XLogReportUnloggedStatement() to the callers of heap_sync(). When I put
it in heap_sync(), I didn't take into account that it's sometimes called
just to flush buffers from buffer cache, not to fsync() non-WAL-logged
operations.As you said, I moved the responsibility of calling XLogReportUnloggedStatement()
to the callers of heap_sync(). Here is the patch.Committed. The use_wal parameter to end_heap_rewrite() was not
necessary, that information is already in RewriteState, so I took that out.Are we going to bump up frontend/backend protocol version 3.0 to 3.x
or some such?
No, this doesn't affect the normal FE/BE protocol. The message header
was added to the streaming replication messages that are sent within
CopyData messages.
--
Heikki Linnakangas
EnterpriseDB http://www.enterprisedb.com