BUG #12324: database's age less then max(relAGE) , and stream standby diff with master - Mailing list pgsql-bugs

From digoal@126.com
Subject BUG #12324: database's age less then max(relAGE) , and stream standby diff with master
Date
Msg-id 20141224035808.11503.56425@wrigleys.postgresql.org
Whole thread Raw
Responses Re: BUG #12324: database's age less then max(relAGE) , and stream standby diff with master
List pgsql-bugs
The following bug has been logged on the website:

Bug reference:      12324
Logged by:          digoal
Email address:      digoal@126.com
PostgreSQL version: 9.0.3
Operating system:   CentOS 5.7 x64
Description:

In a suspected 9.0.3 version bugs? there's no way to reproduce it.
Environment, PG stream replication.
primary: PostgreSQL 9.0.3
standby: PostgreSQL 9.0.3

Access to the data of a certain table do not match the primary node and the
standby node.
The master node 27 has records
digoal=> select * from xxxx where xxx =618;
id  | xxx | xxx |       create_time       | sort_order | push_end_time |
push_start_time | hot
------+-------------+--------------+-------------------------+------------+---------------+-----------------+-----
 6711 |         261 |          618 | 2014-12-16 16:42:19.866 |         22 |
24:00         | 00:00           |   0
 6712 |          37 |          618 | 2014-12-16 16:42:19.881 |         21 |
24:00         | 00:00           |   0
 6713 |         210 |          618 | 2014-12-16 16:42:19.898 |         20 |
24:00         | 00:00           |   0
 6714 |         222 |          618 | 2014-12-16 16:42:19.913 |         19 |
24:00         | 00:00           |   0
 6715 |         190 |          618 | 2014-12-16 16:42:19.929 |         18 |
24:00         | 00:00           |   0
 6716 |         184 |          618 | 2014-12-16 16:42:19.944 |         17 |
24:00         | 00:00           |   0
 6717 |         182 |          618 | 2014-12-16 16:42:19.959 |         16 |
24:00         | 00:00           |   0
 6718 |         157 |          618 | 2014-12-16 16:42:19.977 |         15 |
24:00         | 00:00           |   0
 6719 |         293 |          618 | 2014-12-16 16:42:19.995 |         14 |
24:00         | 00:00           |   0
 6721 |         297 |          618 | 2014-12-16 16:42:20.027 |         12 |
24:00         | 00:00           |   0
 6722 |         171 |          618 | 2014-12-16 16:42:20.044 |         11 |
24:00         | 00:00           |   0
 6723 |         243 |          618 | 2014-12-16 16:42:20.065 |         10 |
24:00         | 00:00           |   0
 6724 |         318 |          618 | 2014-12-16 16:42:20.08  |          9 |
24:00         | 00:00           |   0
 6725 |         232 |          618 | 2014-12-16 16:42:20.096 |          8 |
24:00         | 00:00           |   0
 6726 |         254 |          618 | 2014-12-16 16:42:20.112 |          7 |
24:00         | 00:00           |   0
 6727 |         307 |          618 | 2014-12-16 16:42:20.126 |          6 |
24:00         | 00:00           |   0
 6728 |         181 |          618 | 2014-12-16 16:42:20.143 |          5 |
24:00         | 00:00           |   0
 6729 |         294 |          618 | 2014-12-16 16:42:20.158 |          4 |
24:00         | 00:00           |   0
 6730 |         327 |          618 | 2014-12-16 16:42:20.175 |          3 |
24:00         | 00:00           |   0
 6731 |         309 |          618 | 2014-12-16 16:42:20.19  |          2 |
24:00         | 00:00           |   0
 6706 |          50 |          618 | 2014-12-16 16:42:19.779 |         23 |
24:00         | 00:00           |   0
 6705 |         281 |          618 | 2014-12-16 16:42:19.761 |         29 |
24:00         | 00:00           |   0
 6707 |         300 |          618 | 2014-12-16 16:42:19.797 |         28 |
24:00         | 00:00           |   0
 6709 |         204 |          618 | 2014-12-16 16:42:19.831 |         25 |
24:00         | 00:00           |   0
 6710 |         308 |          618 | 2014-12-16 16:42:19.851 |         24 |
24:00         | 00:00           |   0
 6708 |         195 |          618 | 2014-12-16 16:42:19.813 |         27 |
24:00         | 00:00           |   0
 6720 |         229 |          618 | 2014-12-16 16:42:20.01  |         26 |
24:00         | 00:00           |   0
(27 rows)

There are 62 records for standby nodes
digoal=> select cmin,cmax,xmin,xmax,ctid,id from xxxx where xxx =618;
cmin | cmax |    xmin    | xmax |   ctid   |  id
------+------+------------+------+----------+------
  342 |  342 | 2582467777 |    0 | (23,58)  | 6475
  343 |  343 | 2582467777 |    0 | (23,59)  | 6476
  344 |  344 | 2582467777 |    0 | (23,60)  | 6477
  345 |  345 | 2582467777 |    0 | (23,61)  | 6478
  346 |  346 | 2582467777 |    0 | (23,62)  | 6479
  347 |  347 | 2582467777 |    0 | (23,63)  | 6480
  348 |  348 | 2582467777 |    0 | (23,64)  | 6481
  349 |  349 | 2582467777 |    0 | (23,65)  | 6482
  350 |  350 | 2582467777 |    0 | (23,66)  | 6483
  351 |  351 | 2582467777 |    0 | (23,67)  | 6484
  352 |  352 | 2582467777 |    0 | (23,68)  | 6485
  353 |  353 | 2582467777 |    0 | (23,69)  | 6486
  354 |  354 | 2582467777 |    0 | (23,70)  | 6487
  355 |  355 | 2582467777 |    0 | (23,71)  | 6488
  356 |  356 | 2582467777 |    0 | (23,72)  | 6489
  357 |  357 | 2582467777 |    0 | (23,73)  | 6490
  358 |  358 | 2582467777 |    0 | (23,75)  | 6491
  359 |  359 | 2582467777 |    0 | (23,76)  | 6492
  360 |  360 | 2582467777 |    0 | (23,77)  | 6493
  361 |  361 | 2582467777 |    0 | (23,79)  | 6494
  362 |  362 | 2582467777 |    0 | (23,80)  | 6495
  363 |  363 | 2582467777 |    0 | (23,81)  | 6496
  364 |  364 | 2582467777 |    0 | (23,82)  | 6497
  365 |  365 | 2582467777 |    0 | (23,83)  | 6498
  366 |  366 | 2582467777 |    0 | (23,84)  | 6499
  367 |  367 | 2582467777 |    0 | (23,85)  | 6500
  368 |  368 | 2582467777 |    0 | (23,86)  | 6501
  369 |  369 | 2582467777 |    0 | (23,87)  | 6502
  370 |  370 | 2582467777 |    0 | (23,88)  | 6503
  371 |  371 | 2582467777 |    0 | (23,89)  | 6504
  372 |  372 | 2582467777 |    0 | (23,90)  | 6505
  373 |  373 | 2582467777 |    0 | (23,91)  | 6506
  374 |  374 | 2582467777 |    0 | (23,92)  | 6507
  375 |  375 | 2582467777 |    0 | (23,94)  | 6508
  376 |  376 | 2582467777 |    0 | (23,95)  | 6509
  250 |  250 | 2907809296 |    0 | (28,37)  | 6711
  251 |  251 | 2907809296 |    0 | (28,38)  | 6712
  252 |  252 | 2907809296 |    0 | (28,39)  | 6713
  253 |  253 | 2907809296 |    0 | (28,40)  | 6714
  254 |  254 | 2907809296 |    0 | (28,41)  | 6715
  255 |  255 | 2907809296 |    0 | (28,42)  | 6716
  256 |  256 | 2907809296 |    0 | (28,43)  | 6717
  257 |  257 | 2907809296 |    0 | (28,44)  | 6718
  258 |  258 | 2907809296 |    0 | (28,47)  | 6719
  260 |  260 | 2907809296 |    0 | (28,49)  | 6721
  261 |  261 | 2907809296 |    0 | (28,54)  | 6722
  262 |  262 | 2907809296 |    0 | (28,55)  | 6723
  263 |  263 | 2907809296 |    0 | (28,56)  | 6724
  264 |  264 | 2907809296 |    0 | (28,57)  | 6725
  265 |  265 | 2907809296 |    0 | (28,58)  | 6726
  266 |  266 | 2907809296 |    0 | (28,59)  | 6727
  267 |  267 | 2907809296 |    0 | (28,60)  | 6728
  268 |  268 | 2907809296 |    0 | (28,61)  | 6729
  269 |  269 | 2907809296 |    0 | (28,62)  | 6730
  270 |  270 | 2907809296 |    0 | (28,63)  | 6731
    1 |    1 | 2957409441 |    0 | (28,102) | 6706
    0 |    0 | 2957411736 |    0 | (28,103) | 6705
    0 |    0 | 2957411736 |    0 | (28,104) | 6707
    0 |    0 | 2957409441 |    0 | (28,106) | 6709
    0 |    0 | 2957409441 |    0 | (28,107) | 6710
    0 |    0 | 2957411736 |    0 | (28,108) | 6708
    1 |    1 | 2957411736 |    0 | (28,109) | 6720
(62 rows)

The preferred screening for node XLOG replay and the master node XLOG
location are consistent or close to.
For the node
postgres=# select pg_last_xlog_replay_location();
on standby
pg_last_xlog_replay_location
1521/95AF7FE8
(1 row)
on primary
postgres=# select pg_current_xlog_location();
pg_current_xlog_location
1521/95B4E000
(1 row)
Basic is consistent, because a query manually switch has time lag.

Then make sure no changes to the table.

There is no other reasons for Lord of standby data can be inconsistent with
primary, so is the BUG?

The next , I see database's age small then object's age in
pg_class.relfrozenxid
But this is obviously not normal.
postgres=# select max(age(datfrozenxid)) from pg_database ;
max
1486750538
(1 row)

digoal=> select max(age(relfrozenxid)) from pg_class ;
max
2147483647
(1 row)

On the table for a vacuum after full, primary and standby database data
consistent, returned to normal.
on primary.
digoal=> vacuum full xxxx ;
VACUUM

the cluster's
Vacuum database configuration:
#vacuum_freeze_min_age = 50000000
vacuum_freeze_table_age = 1100000000
autovacuum_freeze_max_age = 1500000000

The next thing to do is to manually perform some vacuum freeze.
> vacuumdb -a -F -z


Other info:
standby:
pg_control version number:            903
Catalog version number:               201008051
Database system identifier:           5574478509073467071
Database cluster state:               in archive recovery
pg_control last modified:             Wed 24 Dec 2014 10:55:30 AM CST
Latest checkpoint location:           1521/861BBA10
Prior checkpoint location:            1521/7C8EF3C0
Latest checkpoint's REDO location:    1521/81884898
Latest checkpoint's TimeLineID:       3
Latest checkpoint's NextXID:          2/3295971686
Latest checkpoint's NextOID:          168863593
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:  0
Latest checkpoint's oldestXID:        1809653736
Latest checkpoint's oldestXID's DB:   164408906
Latest checkpoint's oldestActiveXID:  3295733772
Time of latest checkpoint:            Wed 24 Dec 2014 10:50:10 AM CST
Minimum recovery ending location:     1521/92FAD1B8
Backup start location:                0/0
Current wal_level setting:            hot_standby
Current max_connections setting:      2000
Current max_prepared_xacts setting:   0
Current max_locks_per_xact setting:   64
Maximum data alignment:               8
Database block size:                  8192
Blocks per segment of large relation: 1048576
WAL block size:                       8192
Bytes per WAL segment:                67108864
Maximum length of identifiers:        64
Maximum columns in an index:          32
Maximum size of a TOAST chunk:        1996
Date/time type storage:               64-bit integers
Float4 argument passing:              by value
Float8 argument passing:              by value

primary
pg_control version number:            903
Catalog version number:               201008051
Database system identifier:           5574478509073467071
Database cluster state:               in production
pg_control last modified:             Wed 24 Dec 2014 10:57:33 AM CST
Latest checkpoint location:           1521/8FEA1380
Prior checkpoint location:            1521/861BBA10
Latest checkpoint's REDO location:    1521/8AC9C518
Latest checkpoint's TimeLineID:       3
Latest checkpoint's NextXID:          2/3295971686
Latest checkpoint's NextOID:          168863593
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:  0
Latest checkpoint's oldestXID:        1809653736
Latest checkpoint's oldestXID's DB:   164408906
Latest checkpoint's oldestActiveXID:  3295733772
Time of latest checkpoint:            Wed 24 Dec 2014 10:55:10 AM CST
Minimum recovery ending location:     0/0
Backup start location:                0/0
Current wal_level setting:            hot_standby
Current max_connections setting:      2000
Current max_prepared_xacts setting:   0
Current max_locks_per_xact setting:   64
Maximum data alignment:               8
Database block size:                  8192
Blocks per segment of large relation: 1048576
WAL block size:                       8192
Bytes per WAL segment:                67108864
Maximum length of identifiers:        64
Maximum columns in an index:          32
Maximum size of a TOAST chunk:        1996
Date/time type storage:               64-bit integers
Float4 argument passing:              by value
Float8 argument passing:              by value


Latest checkpoint's NextXID:          2/3298037243
select
txid_visible_in_snapshot((2*2^32+2582467777)::int8,txid_current_snapshot());

pgsql-bugs by date:

Previous
From: egoitz@sarenet.es
Date:
Subject: BUG #12344: libcurses issue with psql binary of Solaris package
Next
From: nikita.y.volkov@mail.ru
Date:
Subject: BUG #12330: ACID is broken for unique constraints