From: | Christoph Ziegenberg <ziegenberg(at)web(dot)de> |
---|---|
To: | Merlin Moncure <mmoncure(at)gmail(dot)com>,Christoph Ziegenberg <ziegenberg(at)web(dot)de> |
Cc: | Jeff Janes <jeff(dot)janes(at)gmail(dot)com>,pgsql-bugs <pgsql-bugs(at)lists(dot)postgresql(dot)org> |
Subject: | Re: BUG #15967: Sequence generation using NEXTVAL() fails on 64bit systems |
Date: | 2019-08-21 05:11:16 |
Message-ID: | 1591F404-9363-4333-AC6C-0C85795DEC2F@web.de |
Views: | Raw Message | Whole Thread | Download mbox | Resend email |
Thread: | |
Lists: | pgsql-bugs |
Good idea with the replacement of the nextval function. This confirms, that the problem is not an application or PHP problem.
Here an extract from the logs, showing the error:
---
2019-08-21 06:57:38.812 CEST [5824] WARNUNG: Got value 2799 from public.e2_ws_log_login_seq
2019-08-21 06:57:38.812 CEST [5824] ZUSAMMENHANG: PL/pgSQL-Funktion log_nextval(text) Zeile 6 bei RAISE
2019-08-21 06:57:38.872 CEST [16236] WARNUNG: Got value 2800 from public.e2_ws_log_login_seq
2019-08-21 06:57:38.872 CEST [16236] ZUSAMMENHANG: PL/pgSQL-Funktion log_nextval(text) Zeile 6 bei RAISE
2019-08-21 06:57:38.873 CEST [1436] WARNUNG: Got value 2801 from public.e2_ws_log_login_seq
2019-08-21 06:57:38.873 CEST [1436] ZUSAMMENHANG: PL/pgSQL-Funktion log_nextval(text) Zeile 6 bei RAISE
2019-08-21 06:57:38.910 CEST [12480] WARNUNG: Got value 2801 from public.e2_ws_log_login_seq
2019-08-21 06:57:38.910 CEST [12480] ZUSAMMENHANG: PL/pgSQL-Funktion log_nextval(text) Zeile 6 bei RAISE
2019-08-21 06:57:38.915 CEST [12480] FEHLER: doppelter Schlüsselwert verletzt Unique-Constraint »p_e2_ws_log_login«
2019-08-21 06:57:38.915 CEST [12480] DETAIL: Schlüssel »(log_login_id)=(2801)« existiert bereits.
2019-08-21 06:57:38.915 CEST [12480] ANWEISUNG: INSERT INTO e2_ws_log_login (log_login_id, client_id, log_action, log_datetime, log_ip_address, log_data) VALUES ($1, $2, $3, $4, $5, $6)
2019-08-21 06:57:39.031 CEST [10672] WARNUNG: Got value 2802 from public.e2_ws_log_login_seq
2019-08-21 06:57:39.031 CEST [10672] ZUSAMMENHANG: PL/pgSQL-Funktion log_nextval(text) Zeile 6 bei RAISE
---
BTW: I had to change the function a little bit:
CREATE OR REPLACE FUNCTION log_nextval(_Sequence TEXT) RETURNS BIGINT AS
$$
DECLARE
s BIGINT;
BEGIN
s := nextval(_Sequence);
RAISE WARNING 'Got value % from %', s, _Sequence;
RETURN s;
END;
$$ LANGUAGE 'plpgsql';
Christoph
Am 20. August 2019 18:06:42 MESZ schrieb Merlin Moncure <mmoncure(at)gmail(dot)com>:
>On Tue, Aug 20, 2019 at 9:56 AM Christoph Ziegenberg
><ziegenberg(at)web(dot)de> wrote:
>> New info:
>> We could also reproduce it with Postgres 10.10 32bit on Windows
>Server 2016 and 9.6.8 64bit on Ubuntu (18.x). So also the 32bit version
>is affected, as well as 9.x versions.
>
>Ok, that makes sense; if we don't have arch specific reproduction I'd
>say that lowers the likelihood of having a serious problem within
>postgres itself (just a hunch).
>
>> Current test state:
>> We (2 of my colleagues and me) are currently trying to create an
>independent test, but at the moment it only occurrs within the specific
>application.
>
>This of course is key. Most people reading this list are going to be
>suspicious of your application rather than postgres internals causing
>the issue. Having said that, let's see if we can isolate the problem.
>
>> Of course we search for an error in the application first, checked
>the connection settings, tracked all statements... there is nothing
>special, only a handful of SELECTS and UPDATES, then the sequence
>generation and the (sometimes failing) INSERT, and another INSERT (no
>sequence generate here) and UPDATE following. In all cases we tested
>with the Postgres default configuration.
>
>> We could see that wrapping the selection of NEXTVAL() in a
>transaction (which shouldn't have any effect?) reduced the problem in
>one case, but it was still possible to reproduce the error with an
>increased number of requests.
>
>Being in a transaction makes shouldn't make any difference with
>regards to behavior.
>
>> At the moment we don't have a real idea how to proceed. Next step
>planned is to simulate all of the aforementioned requests done by the
>application, because they seem to influence the behavior.
>
>Isolating in a separate test would be proof. Sans that, we need to be
>suspicious of your test environment. Hm, how about this: perhaps we
>can tease the problem out with logging. One possible trick is to do
>this:
>CREATE OR REPLACE FUNCTION log_nextval(_Sequence TEXT, s OUT) RETURNS
>BIGINT AS
>$$
>BEGIN
> s := nextval(_Sequence);
> RAISE WARNING 'Got value % from %', s, _Sequence;
> RETURN s;
>END;
>$$ LANGUAGE PLGSQL;
>
>Then, as an experiment, you can move all your nextval() generation to
>this function (note: there will be significant performance hit) and
>attempt to reproduce the problem in your application. If when you
>did, we could then interrogate the database log to see if the same
>value >1 times, this would be a smoking gun. If you did not see the
>value returned >1 times, maybe turn on full statement logging (also a
>big performance hit) and see where your application might be jacking
>things up.
>
>> Background:
>> The application is written in PHP (different versions used in the
>tests, 7.2 - 7.4 I guess), runs on Apache/IIS (FastCGI) and uses the
>PDO extension for the communication with Postgres.
>
>merlin
From | Date | Subject | |
---|---|---|---|
Next Message | Petar Masev | 2019-08-21 06:25:48 | RE: Postgres 11.5.1 failed installation |
Previous Message | Alvaro Herrera | 2019-08-21 02:40:05 | Re: BUG #15964: vacuumdb.c:187:10: error: use of undeclared identifier 'FD_SETSIZE' |