Hi,
On Tuesday, August 21, 2012 02:28:54 PM Maxim Boguk wrote: > On Tue, Aug 21, 2012 at 8:08 PM, Maxim Boguk <maxim.bo...@gmail.com> wrote: > >> > I have kept all that database files for the future investigation. > >> > > >> > What I should look into first? > >> > >> Could you reproduce the error with log_error_verbosity=verbose? Or even > >> better > >> provide a backtrace with gdb? > > > > There log with log_error_verbosity=verbose: > LOG: 00000: database system was interrupted while in recovery at log time > 2012-08-21 08:21:42 MSK > HINT: If this has occurred more than once some data might be corrupted and > you might need to choose an earlier recovery target. > LOCATION: StartupXLOG, xlog.c:5757 > DEBUG: 00000: standby_mode = 'on' > LOCATION: readRecoveryCommandFile, xlog.c:5269 > DEBUG: 00000: primary_conninfo = 'host=10.12.22.19 port=5433 user=replica > password=acilper' > LOCATION: readRecoveryCommandFile, xlog.c:5276 > DEBUG: 00000: trigger_file = '/db/data/failover' > LOCATION: readRecoveryCommandFile, xlog.c:5283 > LOG: 00000: entering standby mode > LOCATION: StartupXLOG, xlog.c:5827 > DEBUG: 00000: checkpoint record is at 925/2D41CAA0 > LOCATION: StartupXLOG, xlog.c:5894 > DEBUG: 00000: redo record is at 925/2C0004C8; shutdown FALSE > LOCATION: StartupXLOG, xlog.c:5929 > DEBUG: 00000: next transaction ID: 0/1768511856; next OID: 59880938 > LOCATION: StartupXLOG, xlog.c:5933 > DEBUG: 00000: next MultiXactId: 361788644; next MultiXactOffset: 822580965 > LOCATION: StartupXLOG, xlog.c:5936 > DEBUG: 00000: oldest unfrozen transaction ID: 1569182525, in database > 16424 LOCATION: StartupXLOG, xlog.c:5939 > DEBUG: 00000: transaction ID wrap limit is 3716666172, limited by database > with OID 16424 > LOCATION: SetTransactionIdLimit, varsup.c:334 > DEBUG: 00000: initializing for hot standby > LOCATION: StartupXLOG, xlog.c:6070 > DEBUG: 00000: my backend id is 1 > LOCATION: SharedInvalBackendInit, sinvaladt.c:326 > LOG: 00000: redo starts at 925/2C0004C8 > LOCATION: StartupXLOG, xlog.c:6199 > DEBUG: 00000: record known xact 1768508078 latestObservedXid 0 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.079655+04 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508078 latestObservedXid 0 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.079655+04 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: remove KnownAssignedXid 1768508078 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.079655+04 > LOCATION: KnownAssignedXidsRemove, procarray.c:2869 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo exclusive_lock: xid 1768508080 rel 1663/16424/17282; > tid 725829/8 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo update: rel 1663/16424/17282; tid 725829/8; new > 726017/7 LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508076 latestObservedXid 0 > CONTEXT: xlog redo exclusive_lock: xid 1768508076 rel 1663/16424/47760635; > tid 3075/136 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/47747; tid 43866/197 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/52546872; tid 44700/276 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508061 latestObservedXid 0 > CONTEXT: xlog redo log: rel 1663/16424/19211 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508082 latestObservedXid 0 > CONTEXT: xlog redo exclusive_lock: xid 1768508082 rel 1663/16424/4759107; > tid 1098/7 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508076 latestObservedXid 0 > CONTEXT: xlog redo hot_update: rel 1663/16424/47760635; tid 3075/136; new > 3075/140 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo exclusive_lock: xid 1768508080 rel 1663/16424/17282; > tid 725918/2 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508082 latestObservedXid 0 > CONTEXT: xlog redo hot_update: rel 1663/16424/4759107; tid 1098/7; new > 1098/39 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo update: rel 1663/16424/17282; tid 725918/2; new > 725918/6 LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/47747; tid 43866/201 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/52546872; tid 44700/276 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.082508+04 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508080 latestObservedXid 0 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.082508+04 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: remove KnownAssignedXid 1768508080 > CONTEXT: xlog redo commit: 2012-08-21 08:21:42.082508+04 > LOCATION: KnownAssignedXidsRemove, procarray.c:2869 > DEBUG: 00000: record known xact 1768508061 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/64654; tid 178183/44 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508061 latestObservedXid 0 > CONTEXT: xlog redo insert: rel 1663/16424/95419; tid 38650/318 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > DEBUG: 00000: record known xact 1768508061 latestObservedXid 0 > > > CONTEXT: xlog redo create multixact 361788644 offset 822580965: 1768508061 > 1768508078 > LOCATION: RecordKnownAssignedTransactionIds, procarray.c:2375 > FATAL: XX000: could not access status of transaction 361788644 > DETAIL: Could not read from file "pg_multixact/offsets/1590" at offset > 114688: Unknown error: 0. > CONTEXT: xlog redo create multixact 361788644 offset 822580965: 1768508061 > 1768508078 > LOCATION: SlruReportIOError, slru.c:840 The strange thing here is the "unknown error: 0" bit. That indicates that slru_errno isn't properly set... > > I have some problems with debug startup process with gdb... > I following next sequence of commands (and got no useful results): Youre debugging the postmaster that way. The easiest way would be to just attach to the startup process with gdb -p. Not sure if you can manage that timingwise without manually adding sleeps. Otherwise you probably will have to work with "set follow-fork-mode ask" in gdb. Getting to the right child isn't easy though. > [pgsql@db1 ~/tmp/postgresql-9.0.8]$ /usr/local/bin/gdb > /usr/local/bin/postgres > ... > Reading symbols from /usr/local/bin/postgres...done. > (gdb) b exit > Breakpoint 1 at 0x44d38c > (gdb) run -D /db/data_back/ > Starting program: /usr/local/bin/postgres -D /db/data_back/ > > Program received signal SIGUSR1, User defined signal 1. > 0x00000008018ddadc in select () from /lib/libc.so.7 > (gdb) bt > #0 0x00000008018ddadc in select () from /lib/libc.so.7 > #1 0x000000000065641c in ServerLoop () at postmaster.c:1396 > #2 0x0000000000655d05 in PostmasterMain (argc=3, argv=0x7fffffffead0) at > postmaster.c:1097 > #3 0x00000000005d974a in main (argc=3, argv=0x7fffffffead0) at main.c:188 > (gdb) cont > Continuing. handle SIGUSR1 nohandle noprint is useful to avoid this btw. > Breakpoint 1, 0x000000080186bab0 in exit () from /lib/libc.so.7 > (gdb) bt > #0 0x000000080186bab0 in exit () from /lib/libc.so.7 > #1 0x000000000067d0a6 in proc_exit (code=1) at ipc.c:137 > #2 0x0000000000659933 in ExitPostmaster (status=1) at postmaster.c:4172 > #3 0x0000000000657d2d in reaper (postgres_signal_arg=20) at > postmaster.c:2354 > #4 <signal handler called> > #5 <signal handler called> > #6 0x00000008018ddadc in select () from /lib/libc.so.7 > #7 0x000000000065641c in ServerLoop () at postmaster.c:1396 > #8 0x0000000000655d05 in PostmasterMain (argc=3, argv=0x7fffffffead0) at > postmaster.c:1097 > #9 0x00000000005d974a in main (argc=3, argv=0x7fffffffead0) at main.c:188 > (gdb) cont > Continuing. > [Inferior 1 (process 98857) exited with code 01] > (gdb) quit Andres -- Andres Freund http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services -- Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-bugs
