Обсуждение: WAL: postmaster won't start

It seems postmaster won't restart under WAL. What I have done so far
was creating some tables and inserting fairly large amount of tuples
(100000 tuples) using pgbench.

Here is the test sequence:

pg_ctl -w stop
rm -fr /usr/local/pgsql/data
initdb
pg_ctl -w start
createdb test
./pgbench -i test
pg_ctl -w -m i stop
pg_ctl -w start

and postmaster does not return from automatic recovering job. Here are
last 2 lines from log:

Nov  1 12:38:46 srapc968-yotsuya postgres[14769]: [7] DEBUG:  The DataBase system was not properly shut down
^IAutomaticrecovery is in progress...
 
Nov  1 12:38:46 srapc968-yotsuya postgres[14769]: [8] DEBUG:  Redo starts at (0, 287536)

It seems that the recovery process is waiting for acquiring a lock.
Here is the backtrace from the process:

(gdb) where
#0  0x2ac4acae in __select () from /lib/libc.so.6
#1  0x2ac9f0ac in ?? ()
#2  0x80ea18c in LockBuffer (buffer=37, mode=2) at xlog_bufmgr.c:1995
#3  0x8082feb in XLogReadBuffer (extend=0, reln=0x82e92c8, blkno=1)   at xlogutils.c:215
#4  0x80781e4 in btree_xlog_delete (redo=1, lsn={xlogid = 0,      xrecoff = 23741124}, record=0x82980dc) at
nbtree.c:1013
#5  0x80790fe in btree_redo (lsn={xlogid = 0, xrecoff = 23741124},    record=0x82980dc) at nbtree.c:1450
#6  0x80825b2 in StartupXLOG () at xlog.c:1452
#7  0x80850cd in BootstrapMain (argc=6, argv=0x7fffeffc) at bootstrap.c:349
#8  0x80e047a in SSDataBase (startup=1 '\001') at postmaster.c:2187
#9  0x80deb1a in PostmasterMain (argc=1, argv=0x7ffff694) at postmaster.c:667
#10 0x80c3646 in main (argc=1, argv=0x7ffff694) at main.c:112

Please let me know if you need more info.
--
Tatsuo Ishii

Did you turn XLOG_DEBUG off?
With XLOG_DEBUG on there should be lines in log like

REDO @ 0/434100; LSN 0/434252: .........

before control would reach btree_redo...

Ok, anyway btree_xlog_delete is fixed. Thanks, Tatsuo!
And please try again -:)

Vadim

> It seems postmaster won't restart under WAL. What I have done so far
> was creating some tables and inserting fairly large amount of tuples
> (100000 tuples) using pgbench.
> 
> Here is the test sequence:
> 
> pg_ctl -w stop
> rm -fr /usr/local/pgsql/data
> initdb
> pg_ctl -w start
> createdb test
> ./pgbench -i test
> pg_ctl -w -m i stop
> pg_ctl -w start
> 
> and postmaster does not return from automatic recovering job. Here are
> last 2 lines from log:
> 
> Nov  1 12:38:46 srapc968-yotsuya postgres[14769]: [7] DEBUG:  
> The DataBase system was not properly shut down ^IAutomatic 
> recovery is in progress...
> Nov  1 12:38:46 srapc968-yotsuya postgres[14769]: [8] DEBUG:  
> Redo starts at (0, 287536)
> 
> It seems that the recovery process is waiting for acquiring a lock.
> Here is the backtrace from the process:
> 
> (gdb) where
> #0  0x2ac4acae in __select () from /lib/libc.so.6
> #1  0x2ac9f0ac in ?? ()
> #2  0x80ea18c in LockBuffer (buffer=37, mode=2) at xlog_bufmgr.c:1995
> #3  0x8082feb in XLogReadBuffer (extend=0, reln=0x82e92c8, blkno=1)
>     at xlogutils.c:215
> #4  0x80781e4 in btree_xlog_delete (redo=1, lsn={xlogid = 0, 
>       xrecoff = 23741124}, record=0x82980dc) at nbtree.c:1013
> #5  0x80790fe in btree_redo (lsn={xlogid = 0, xrecoff = 23741124}, 
>     record=0x82980dc) at nbtree.c:1450
> #6  0x80825b2 in StartupXLOG () at xlog.c:1452
> #7  0x80850cd in BootstrapMain (argc=6, argv=0x7fffeffc) at 
> bootstrap.c:349
> #8  0x80e047a in SSDataBase (startup=1 '\001') at postmaster.c:2187
> #9  0x80deb1a in PostmasterMain (argc=1, argv=0x7ffff694) at 
> postmaster.c:667
> #10 0x80c3646 in main (argc=1, argv=0x7ffff694) at main.c:112
> 
> Please let me know if you need more info.
> --
> Tatsuo Ishii
> 

> Did you turn XLOG_DEBUG off?
> With XLOG_DEBUG on there should be lines in log like
> 
> REDO @ 0/434100; LSN 0/434252: .........
> 
> before control would reach btree_redo...

No. I just started up postmaster with -S (logs are forwarded to syslog
in my settings).

> Ok, anyway btree_xlog_delete is fixed. Thanks, Tatsuo!
> And please try again -:)

Thanks. I will try again.
--
Tatsuo Ishii

> > Did you turn XLOG_DEBUG off?
> > With XLOG_DEBUG on there should be lines in log like
> > 
> > REDO @ 0/434100; LSN 0/434252: .........
> > 
> > before control would reach btree_redo...
> 
> No. I just started up postmaster with -S (logs are forwarded to syslog
> in my settings).

Oh. XLOG_DEBUG calls write(2,) - too big output for syslog I think.

Vadim

> > No. I just started up postmaster with -S (logs are forwarded to syslog
> > in my settings).
> 
> Oh. XLOG_DEBUG calls write(2,) - too big output for syslog I think.

I see. Next time I will turn off -S so that I could send you
XLOG_DEBUG outputs...
--
Tatsuo Ishii