Horton

Thread

  1. Re: BUG #19345: MemoryContextSizeFailure after upgrade 14.11 to 17.7 in stored procedure

    weijie JL <weijie1006jl@gmail.com> — 2025-12-09T11:30:57Z

    I found this information in the log：

2025-12-09 09:01:43.384 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892120", size 1073741824
2025-12-09 09:01:43.384 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.451 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892121", size 1073741824
2025-12-09 09:01:43.451 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.518 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892122", size 1073741824
2025-12-09 09:01:43.518 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.604 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892123", size 1073741824
2025-12-09 09:01:43.604 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.672 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892124", size 1073741824
2025-12-09 09:01:43.672 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.737 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892125", size 1073741824
2025-12-09 09:01:43.737 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.806 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892126", size 1073741824
2025-12-09 09:01:43.806 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.874 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892127", size 1073741824
2025-12-09 09:01:43.874 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:43.940 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892128", size 1073741824
2025-12-09 09:01:43.940 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.007 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892129", size 1073741824
2025-12-09 09:01:44.007 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.073 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892130", size 1073741824
2025-12-09 09:01:44.073 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.140 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892131", size 1073741824
2025-12-09 09:01:44.140 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.207 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892132", size 1073741824
2025-12-09 09:01:44.207 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.272 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892133", size 1073741824
2025-12-09 09:01:44.272 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.340 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892134", size 1073741824
2025-12-09 09:01:44.340 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:44.406 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892135", size 1069645824
2025-12-09 09:01:44.406 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:01:46.030 CST 10.10.17.192(44780) pgdb_md md [467056]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp467056.0", size 356745216
2025-12-09 09:12:24.606 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:12:24.674 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892137", size 1073741824
2025-12-09 09:12:24.674 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:12:24.747 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892138", size 1073741824
2025-12-09 09:12:24.747 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:12:24.814 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892139", size 1073741824
2025-12-09 09:12:24.814 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:12:27.941 CST 10.10.17.192(46184) pgdb_md md [479218]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp479218.4", size 356745216
2025-12-09 09:41:05.279 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:41:24.385 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 09:41:32.003 CST 10.10.17.192(51364) pgdb_md md [518956]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp518956.10", size 356761600
2025-12-09 10:23:18.997 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.043 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892166", size 392716288
2025-12-09 10:23:19.043 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.089 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892146", size 571425269
2025-12-09 10:23:19.089 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.159 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892149", size 1073741824
2025-12-09 10:23:19.159 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.222 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892148", size 965312512
2025-12-09 10:23:19.222 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.308 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892145", size 1073741824
2025-12-09 10:23:19.308 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:19.350 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp269407.25892150", size 369754112
2025-12-09 10:23:19.350 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:23:21.524 CST 10.10.17.192(58298) pgdb_md md [571449]LOG:  00000: temporary file: path "base/pgsql_tmp/pgsql_tmp571449.9", size 356769792
2025-12-09 10:25:02.481 CST 10.21.18.87(44346) pgdb_md md [269407]STATEMENT:  CALL PR_MD()
2025-12-09 10:47:41.771 CST 10.21.18.87(44346) pgdb_md md [269407]LOG:  00000: duration: 35252734.115 ms  execute <unnamed>: CALL PR_MD()
2025-12-09 10:47:41.771 CST 10.21.18.87(44346) pgdb_md md [269407]LOCATION:  exec_execute_message, postgres.c:2348


> 2025年12月7日 05:04，Tom Lane <tgl@sss.pgh.pa.us> 写道：
> 
> PG Bug reporting form <noreply@postgresql.org> writes:
>> After upgrading from PostgreSQL 14.11 to PostgreSQL 17.7 on our production
>> environment (RockyLinux8, RPM package), we encountered a crash when
>> executing a specific stored procedure.
> 
>> This procedure ran successfully in 14.11 (approximately 8 hours execution
>> time), but on 17.7 it runs for about 6 hours before failing with:
>> LOCATION:  MemoryContextSizeFailure, mcxt.c:1169
>> [3717604]BACKTRACE:
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748) CALL()
>> [0x50d5e0]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748) CALL()
>> [0x9c96dc]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748)
>> CALL(MemoryContextAllocZero+0x14) [0x9cfb54]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748)
>> CALL(ResourceOwnerEnlarge+0x9f) [0x9d218f]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748)
>> CALL(OpenTemporaryFile+0x64) [0x83dfc4]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748)
>> CALL(BufFileCreateTemp+0x18) [0x83a288]
>>        postgres: postgres003: md pgdb_md 10.21.18.87(53748)
>> CALL(ExecHashJoinSaveTuple+0x68) [0x6e1ce8]
> 
> Hmm.  Apparently, your hash join tried to use so many temporary files
> that it needed a more-than-1GB array just to track them all.  One could
> guess that it had been in swap hell for some hours before reaching
> this point, because that'd imply about a terabyte worth of I/O
> buffers, never mind the actual hashtable data.
> 
> Too-many-batches (resulting in too-many-temp-files) is a known failure
> mechanism for our hash join code.  We've tried to improve that in v18
> (cf commits a1b4f289b, aa151022e), but I don't think there's any
> appetite for back-patching that work into older branches.
> 
>> Observations / Workarounds Tested:
>> SET enable_hashjoin = off; → procedure runs successfully.
>> SET hash_mem_multiplier = 1; → procedure runs successfully.
> 
> I'm curious whether the change of hash_mem_multiplier causes it
> to not use a hash join, or that is just successful at limiting
> the hash table growth to a point short of failure.
> 
> 			regards, tom lane