Re: BUG #17949: Adding an index introduces serialisation anomalies.

From: Dmitry Dolgov <9erthalion6(at)gmail(dot)com>
To: Thomas Munro <thomas(dot)munro(at)gmail(dot)com>
Cc: artem(dot)anisimov(dot)255(at)gmail(dot)com, pgsql-bugs(at)lists(dot)postgresql(dot)org
Subject: Re: BUG #17949: Adding an index introduces serialisation anomalies.
Date: 2023-06-15 07:29:28
Message-ID: 20230615072928.u3eypnf3evdikdas@ddolgov.remote.csb
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

> On Mon, May 29, 2023 at 09:29:09PM -0400, Thomas Munro wrote:
> Starred
>
> Hi,
>
> Reproduced here. Thanks for the reproducer. I agree that something
> is wrong here, but I haven't had time to figure out what, yet, but let
> me share what I noticed so far... I modified your test to add a pid
> column to the locks table and to insert insert pg_backend_pid() into
> it, and got:
>
> postgres=# select xmin, * from locks;
>
> ┌───────┬──────┬───────┐
> │ xmin │ path │ pid │
> ├───────┼──────┼───────┤
> │ 17634 │ xyz │ 32932 │
> │ 17639 │ xyz │ 32957 │
> └───────┴──────┴───────┘
>
> Then I filtered the logs (having turned the logging up to capture all
> queries) so I could see just those PIDs and saw this sequence:
>
> 2023-05-29 00:15:43.933 EDT [32932] LOG: duration: 0.182 ms
> statement: BEGIN TRANSACTION ISOLATION LEVEL SERIALIZABLE
> 2023-05-29 00:15:43.934 EDT [32957] LOG: duration: 0.276 ms
> statement: BEGIN TRANSACTION ISOLATION LEVEL SERIALIZABLE
> 2023-05-29 00:15:43.935 EDT [32932] LOG: duration: 1.563 ms
> statement: SELECT * FROM locks WHERE path = 'xyz'
> 2023-05-29 00:15:43.936 EDT [32932] LOG: duration: 0.126 ms
> statement: INSERT INTO locks(path, pid) VALUES('xyz',
> pg_backend_pid())
> 2023-05-29 00:15:43.937 EDT [32957] LOG: duration: 2.191 ms
> statement: SELECT * FROM locks WHERE path = 'xyz'
> 2023-05-29 00:15:43.937 EDT [32957] LOG: duration: 0.261 ms
> statement: INSERT INTO locks(path, pid) VALUES('xyz',
> pg_backend_pid())
> 2023-05-29 00:15:43.937 EDT [32932] LOG: duration: 0.222 ms statement: COMMIT
> 2023-05-29 00:15:43.939 EDT [32957] LOG: duration: 1.775 ms statement: COMMIT

I've tried to reproduce it as well, adding more logging around the
serialization code. If it helps, what I observe is the second
overlapping transaction, that has started a bit later, do not error out
because in OnConflict_CheckForSerializationFailure (when checking for
"writer has become a pivot") there are no more conflicts received from
SHMQueueNext. All the rest of the reported serialization conflicts are
coming from this check, so I assume the incorrect transaction should
fail there too. Not sure yet why is that so.

In response to

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message PG Bug reporting form 2023-06-15 08:20:39 BUG #17978: Unexpected error: "wrong varnullingrels (b) (expected (b 5)) for Var 6/2" triggered by JOIN
Previous Message Richard Guo 2023-06-15 07:12:01 Re: BUG #17976: Inconsistent results of SELECT using CASE WHEN clause