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

Search Discussions

  • Heikki Linnakangas at Feb 1, 2010 at 9:34 am

    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
  • Simon Riggs at Feb 1, 2010 at 9:53 am

    On Mon, 2010-02-01 at 11:33 +0200, Heikki Linnakangas wrote:
    Can you reproduce that?
    Every time

    --
    Simon Riggs www.2ndQuadrant.com
  • Heikki Linnakangas at Feb 1, 2010 at 10:12 am

    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
  • Simon Riggs at Feb 1, 2010 at 10:15 am

    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
  • Heikki Linnakangas at Feb 1, 2010 at 10:30 am

    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
  • Fujii Masao at Feb 1, 2010 at 10:38 am

    On Mon, Feb 1, 2010 at 7:30 PM, Heikki Linnakangas 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 at Feb 1, 2010 at 10:41 am

    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
  • Fujii Masao at Feb 2, 2010 at 4:40 am

    On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas 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
  • Heikki Linnakangas at Feb 3, 2010 at 10:10 am

    Fujii Masao wrote:
    On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
    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
  • Tatsuo Ishii at Feb 3, 2010 at 10:19 am

    Fujii Masao wrote:
    On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
    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
  • Heikki Linnakangas at Feb 3, 2010 at 10:50 am

    Tatsuo Ishii wrote:
    Fujii Masao wrote:
    On Mon, Feb 1, 2010 at 7:40 PM, Heikki Linnakangas
    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
  • Simon Riggs at Feb 1, 2010 at 10:46 am

    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 at Feb 1, 2010 at 9:58 am

    On Mon, Feb 1, 2010 at 6:33 PM, Heikki Linnakangas 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
  • Fujii Masao at Feb 1, 2010 at 10:15 am

    On Mon, Feb 1, 2010 at 6:58 PM, Fujii Masao 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
  • Heikki Linnakangas at Feb 1, 2010 at 10:27 am

    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
  • Fujii Masao at Feb 1, 2010 at 10:37 am

    On Mon, Feb 1, 2010 at 7:27 PM, Heikki Linnakangas 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
  • Tom Lane at Feb 1, 2010 at 4:14 pm

    Fujii Masao writes:
    On Mon, Feb 1, 2010 at 7:27 PM, Heikki Linnakangas
    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

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
grouppgsql-hackers @
categoriespostgresql
postedFeb 1, '10 at 8:41a
activeFeb 3, '10 at 10:50a
posts18
users5
websitepostgresql.org...
irc#postgresql

People

Translate

site design / logo © 2021 Grokbase