Re: Direct I/O

Hi,

On 2023-04-08 16:59:20 +1200, Thomas Munro wrote:
> On Sat, Apr 8, 2023 at 4:47 PM Thomas Munro <thomas.munro@gmail.com> wrote:
> > After a bit more copy-editing on docs and comments and a round of
> > automated indenting, I have now pushed this.  I will now watch the
> > build farm.  I tested on quite a few OSes that I have access to, but
> > this is obviously a very OS-sensitive kind of a thing.
> 
> Hmm.  I see a strange "invalid page" failure on Andrew's machine crake
> in 004_io_direct.pl.  Let's see what else comes in.

There were some failures in CI (e.g. [1] (and perhaps also bf, didn't yet
check), about "no unpinned buffers available".  I was worried for a moment
that this could actually be relation to the bulk extension patch.

But it looks like it's older - and not caused by direct_io support (except by
way of the test existing). I reproduced the issue locally by setting s_b even
lower, to 16 and made the ERROR a PANIC.

#4  0x00005624dfe90336 in errfinish (filename=0x5624df6867c0
"../../../../home/andres/src/postgresql/src/backend/storage/buffer/freelist.c",lineno=353, 
 
    funcname=0x5624df686900 <__func__.6> "StrategyGetBuffer") at
../../../../home/andres/src/postgresql/src/backend/utils/error/elog.c:604
#5  0x00005624dfc71dbe in StrategyGetBuffer (strategy=0x0, buf_state=0x7ffd4182137c, from_ring=0x7ffd4182137b)
    at ../../../../home/andres/src/postgresql/src/backend/storage/buffer/freelist.c:353
#6  0x00005624dfc6a922 in GetVictimBuffer (strategy=0x0, io_context=IOCONTEXT_NORMAL)
    at ../../../../home/andres/src/postgresql/src/backend/storage/buffer/bufmgr.c:1601
#7  0x00005624dfc6a29f in BufferAlloc (smgr=0x5624e1ff27f8, relpersistence=112 'p', forkNum=MAIN_FORKNUM, blockNum=16,
strategy=0x0,foundPtr=0x7ffd418214a3, 
 
    io_context=IOCONTEXT_NORMAL) at ../../../../home/andres/src/postgresql/src/backend/storage/buffer/bufmgr.c:1290
#8  0x00005624dfc69c0c in ReadBuffer_common (smgr=0x5624e1ff27f8, relpersistence=112 'p', forkNum=MAIN_FORKNUM,
blockNum=16,mode=RBM_NORMAL, strategy=0x0, 
 
    hit=0x7ffd4182156b) at ../../../../home/andres/src/postgresql/src/backend/storage/buffer/bufmgr.c:1056
#9  0x00005624dfc69335 in ReadBufferExtended (reln=0x5624e1ee09f0, forkNum=MAIN_FORKNUM, blockNum=16, mode=RBM_NORMAL,
strategy=0x0)
    at ../../../../home/andres/src/postgresql/src/backend/storage/buffer/bufmgr.c:776
#10 0x00005624df8eb78a in log_newpage_range (rel=0x5624e1ee09f0, forknum=MAIN_FORKNUM, startblk=0, endblk=45,
page_std=false)
    at ../../../../home/andres/src/postgresql/src/backend/access/transam/xloginsert.c:1290
#11 0x00005624df9567e7 in smgrDoPendingSyncs (isCommit=true, isParallelWorker=false)
    at ../../../../home/andres/src/postgresql/src/backend/catalog/storage.c:837
#12 0x00005624df8d1dd2 in CommitTransaction () at
../../../../home/andres/src/postgresql/src/backend/access/transam/xact.c:2225
#13 0x00005624df8d2da2 in CommitTransactionCommand () at
../../../../home/andres/src/postgresql/src/backend/access/transam/xact.c:3060
#14 0x00005624dfcbe0a1 in finish_xact_command () at
../../../../home/andres/src/postgresql/src/backend/tcop/postgres.c:2779
#15 0x00005624dfcbb867 in exec_simple_query (query_string=0x5624e1eacd98 "create table t1 as select 1 as i from
generate_series(1,10000)")
 
    at ../../../../home/andres/src/postgresql/src/backend/tcop/postgres.c:1299
#16 0x00005624dfcc09c4 in PostgresMain (dbname=0x5624e1ee40e8 "postgres", username=0x5624e1e6c5f8 "andres")
    at ../../../../home/andres/src/postgresql/src/backend/tcop/postgres.c:4623
#17 0x00005624dfbecc03 in BackendRun (port=0x5624e1ed8250) at
../../../../home/andres/src/postgresql/src/backend/postmaster/postmaster.c:4461
#18 0x00005624dfbec48e in BackendStartup (port=0x5624e1ed8250) at
../../../../home/andres/src/postgresql/src/backend/postmaster/postmaster.c:4189
#19 0x00005624dfbe8541 in ServerLoop () at
../../../../home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1779
#20 0x00005624dfbe7e56 in PostmasterMain (argc=4, argv=0x5624e1e6a520) at
../../../../home/andres/src/postgresql/src/backend/postmaster/postmaster.c:1463
#21 0x00005624dfad538b in main (argc=4, argv=0x5624e1e6a520) at
../../../../home/andres/src/postgresql/src/backend/main/main.c:200


If you look at log_newpage_range(), it's not surprising that we get this error
- it pins up to 32 buffers at once.

Afaics log_newpage_range() originates in 9155580fd5fc, but this caller is from
c6b92041d385.


It doesn't really seem OK to me to unconditionally pin 32 buffers. For the
relation extension patch I introduced LimitAdditionalPins() to deal with this
concern. Perhaps it needs to be exposed and log_newpage_buffers() should use
it?


Do we care about fixing this in the backbranches? Probably not, given there
haven't been user complaints?


Greetings,

Andres Freund

[1] https://cirrus-ci.com/task/4519721039560704