Re: logical decoding : exceeded maxAllocatedDescs for .spill files

Amit Kapila <[email protected]> Sat, 11 Jan 2020 11:06:35 +0530
Newsgroups gmane.comp.db.postgresql.devel.general
Message-ID <CAA4eK1KdmUTUaRfUhViLimgEk-u4tVE9F-_N=Xk+Dyvh95H67g@mail.gmail.com>
On Fri, Jan 10, 2020 at 9:31 AM Amit Kapila <[email protected]> wrote:
>
> On Fri, Jan 10, 2020 at 6:10 AM Tom Lane <[email protected]> wrote:
> >
> > I wrote:
> > >           ReorderBuffer: 223302560 total in 26995 blocks; 7056 free (3 chunks); 223295504 used
> >
> > > The test case is only inserting 50K fairly-short rows, so this seems
> > > like an unreasonable amount of memory to be consuming for that; and
> > > even if you think it's reasonable, it clearly isn't going to scale
> > > to large production transactions.
> >
> > > Now, the good news is that v11 and later get through
> > > 006_logical_decoding.pl just fine under the same restriction.
> > > So we did something in v11 to fix this excessive memory consumption.
> > > However, unless we're willing to back-port whatever that was, this
> > > test case is clearly consuming excessive resources for the v10 branch.
> >
> > I dug around a little in the git history for backend/replication/logical/,
> > and while I find several commit messages mentioning memory leaks and
> > faulty spill logic, they all claim to have been back-patched as far
> > as 9.4.
> >
> > It seems reasonably likely to me that this result is telling us about
> > an actual bug, ie, faulty back-patching of one or more of those fixes
> > into v10 and perhaps earlier branches.
> >
>
> I think it would be good to narrow down this problem, but it seems we
> can do this separately.   I think to avoid forgetting about this, can
> we track it somewhere as an open issue (In Older Bugs section of
> PostgreSQL 12 Open Items or some other place)?
>
> It seems to me that this test has found a problem in back-branches, so
> we might want to keep it after removing the max_files_per_process
> restriction.  However, unless we narrow down this memory leak it is
> not a good idea to keep it at least not in v10.  So, we have the below
> options:
> (a) remove this test entirely from all branches and once we found the
> memory leak problem in back-branches, then consider adding it again
> without max_files_per_process restriction.
> (b) keep this test without max_files_per_process restriction till v11
> and once the memory leak issue in v10 is found, we can back-patch to
> v10 as well.
>

I am planning to go with option (a) and attached are patches to revert
the entire test on HEAD and back branches.  I am planning to commit
these by Tuesday unless someone has a better idea.

-- 
With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com
HEAD-0001-Revert-test-added-by-commit-d207038053.patch (application/octet-stream, 2.7 KB)
From 5e6c86e9692462a21aa5ebb915f8514f7500d152 Mon Sep 17 00:00:00 2001
From: Amit Kapila <[email protected]>
Date: Sat, 11 Jan 2020 10:24:48 +0530
Subject: [PATCH] Revert test added by commit d207038053.

This test was trying to test the mechanism to release kernel FDs as needed
to get us under the max_safe_fds limit in case of spill files.  To do that,
it needs to set max_files_per_process to a very low value which doesn't
even permit starting of the server in the case when there are a few already
opened files.  This test also won't work on platforms where we use one FD
per semaphore.

Backpatch-through: 10, till where this test was added
Discussion:
https://postgr.es/m/CAA4eK1LHhERi06Q+MmP9qBXBBboi+7WV3910J0aUgz71LcnKAw@mail.gmail.com
https://postgr.es/m/[email protected]
---
 src/test/recovery/t/006_logical_decoding.pl | 40 +----------------------------
 1 file changed, 1 insertion(+), 39 deletions(-)

diff --git a/src/test/recovery/t/006_logical_decoding.pl b/src/test/recovery/t/006_logical_decoding.pl
index 216003c..c23cc4d 100644
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -7,7 +7,7 @@ use strict;
 use warnings;
 use PostgresNode;
 use TestLib;
-use Test::More tests => 11;
+use Test::More tests => 10;
 use Config;
 
 # Initialize master node
@@ -135,43 +135,5 @@ is($node_master->psql('postgres', 'DROP DATABASE otherdb'),
 is($node_master->slot('otherdb_slot')->{'slot_name'},
 	undef, 'logical slot was actually dropped with DB');
 
-# Test to ensure that we don't run out of file descriptors even if there
-# are more spill files than maxAllocatedDescs.
-
-# Set max_files_per_process to a small value to make it more likely to run out
-# of max open file descriptors.
-$node_master->safe_psql('postgres',
-	'ALTER SYSTEM SET max_files_per_process = 26;');
-$node_master->restart;
-
-$node_master->safe_psql(
-	'postgres', q{
-do $$
-BEGIN
-    FOR i IN 1..10 LOOP
-        BEGIN
-            INSERT INTO decoding_test(x) SELECT generate_series(1,5000);
-        EXCEPTION
-            when division_by_zero then perform 'dummy';
-        END;
-    END LOOP;
-END $$;
-});
-
-$result = $node_master->safe_psql('postgres',
-	qq[
-set logical_decoding_work_mem to 64; -- generate plenty of .spill files
-SELECT data from pg_logical_slot_get_changes('test_slot', NULL, NULL)
-    WHERE data LIKE '%INSERT%' ORDER BY lsn LIMIT 1;
-]);
-
-$expected = q{table public.decoding_test: INSERT: x[integer]:1 y[text]:null};
-is($result, $expected, 'got expected output from spilling subxacts session');
-
-# Reset back max_files_per_process
-$node_master->safe_psql('postgres',
-	'ALTER SYSTEM SET max_files_per_process = DEFAULT;');
-$node_master->restart;
-
 # done with the node
 $node_master->stop;
-- 
1.8.3.1
v12-0001-Revert-test-added-by-commit-d207038053.patch (application/octet-stream, 2.7 KB)
From dbb12885d645e337daf06a730eca5385993593bc Mon Sep 17 00:00:00 2001
From: Amit Kapila <[email protected]>
Date: Sat, 11 Jan 2020 10:44:39 +0530
Subject: [PATCH] Revert test added by commit d207038053.

This test was trying to test the mechanism to release kernel FDs as needed
to get us under the max_safe_fds limit in case of spill files.  To do that,
it needs to set max_files_per_process to a very low value which doesn't
even permit starting of the server in the case when there are a few already
opened files.  This test also won't work on platforms where we use one FD
per semaphore.

Backpatch-through: 10, till where this test was added
Discussion:
https://postgr.es/m/CAA4eK1LHhERi06Q+MmP9qBXBBboi+7WV3910J0aUgz71LcnKAw@mail.gmail.com
https://postgr.es/m/[email protected]
---
 src/test/recovery/t/006_logical_decoding.pl | 39 +----------------------------
 1 file changed, 1 insertion(+), 38 deletions(-)

diff --git a/src/test/recovery/t/006_logical_decoding.pl b/src/test/recovery/t/006_logical_decoding.pl
index 05693df..c23cc4d 100644
--- a/src/test/recovery/t/006_logical_decoding.pl
+++ b/src/test/recovery/t/006_logical_decoding.pl
@@ -7,7 +7,7 @@ use strict;
 use warnings;
 use PostgresNode;
 use TestLib;
-use Test::More tests => 11;
+use Test::More tests => 10;
 use Config;
 
 # Initialize master node
@@ -135,42 +135,5 @@ is($node_master->psql('postgres', 'DROP DATABASE otherdb'),
 is($node_master->slot('otherdb_slot')->{'slot_name'},
 	undef, 'logical slot was actually dropped with DB');
 
-# Test to ensure that we don't run out of file descriptors even if there
-# are more spill files than maxAllocatedDescs.
-
-# Set max_files_per_process to a small value to make it more likely to run out
-# of max open file descriptors.
-$node_master->safe_psql('postgres',
-	'ALTER SYSTEM SET max_files_per_process = 26;');
-$node_master->restart;
-
-$node_master->safe_psql(
-	'postgres', q{
-do $$
-BEGIN
-    FOR i IN 1..10 LOOP
-        BEGIN
-            INSERT INTO decoding_test(x) SELECT generate_series(1,5000);
-        EXCEPTION
-            when division_by_zero then perform 'dummy';
-        END;
-    END LOOP;
-END $$;
-});
-
-$result = $node_master->safe_psql('postgres',
-	qq[
-SELECT data from pg_logical_slot_get_changes('test_slot', NULL, NULL)
-    WHERE data LIKE '%INSERT%' ORDER BY lsn LIMIT 1;
-]);
-
-$expected = q{table public.decoding_test: INSERT: x[integer]:1 y[text]:null};
-is($result, $expected, 'got expected output from spilling subxacts session');
-
-# Reset back max_files_per_process
-$node_master->safe_psql('postgres',
-	'ALTER SYSTEM SET max_files_per_process = DEFAULT;');
-$node_master->restart;
-
 # done with the node
 $node_master->stop;
-- 
1.8.3.1