pg.ddx.io pgsql-bugs@postgresql.org mailing list archive
help / color / mirror / Atom feedlong analyze, libc bug and libicu
6+ messages / 5 participants
[nested] [flat]
* long analyze, libc bug and libicu
@ 2018-07-05 15:05 Grigory Smolkin <g.smolkin@postgrespro.ru>
0 siblings, 1 reply; 6+ messages in thread
From: Grigory Smolkin @ 2018-07-05 15:05 UTC (permalink / raw)
To: pgsql-bugs
Hello, everyone!
One of your clients with PostgreSQL 10.4 recently noticed that ANALYZE
started to take unproportionally long amount of time. Backtrace:
#0 0x00007f244b68ca06 in strcoll_l () from /lib/x86_64-linux-gnu/libc.so.6
#1 0x00007f244e37802d in varstrfastcmp_locale (x=139794027137284,
y=139794027967812, ssup=<optimized out>) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/backend/utils/adt/varlena.c:2185
#2 0x00007f244e0d6b15 in ApplySortComparator (isNull1=0 '\000',
isNull2=0 '\000', ssup=0x7fffa958de80, datum2=<optimized out>,
datum1=<optimized out>) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/include/utils/sortsupport.h:225
#3 compare_scalars (a=<optimized out>, b=<optimized out>,
arg=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/backend/commands/analyze.c:2821
#4 0x00007f244e3e1023 in med3 (a=0x7f24578f6bd8 "\224__U$\177",
b=0x7f24578f6c78 "\004ITU$\177", c=0x7f24578f6d18 "D\365`U$\177",
cmp=0x7f244e0d6af0 <compare_scalars>, arg=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:108
#5 0x00007f244e3e13ec in qsort_arg (a=a@entry=0x7f24578f6bd8,
n=<optimized out>, n@entry=82, es=es@entry=16,
cmp=cmp@entry=0x7f244e0d6af0 <compare_scalars>,
arg=arg@entry=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:157
#6 0x00007f244e3e1475 in qsort_arg (a=a@entry=0x7f24578f6248,
n=<optimized out>, n@entry=235, es=es@entry=16,
cmp=cmp@entry=0x7f244e0d6af0 <compare_scalars>,
arg=arg@entry=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:217
#7 0x00007f244e3e1475 in qsort_arg (a=a@entry=0x7f24578f5348,
n=<optimized out>, es=es@entry=16, cmp=cmp@entry=0x7f244e0d6af0
<compare_scalars>, arg=arg@entry=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:217
#8 0x00007f244e3e13ac in qsort_arg (a=a@entry=0x7f24578f5348,
n=<optimized out>, es=es@entry=16, cmp=cmp@entry=0x7f244e0d6af0
<compare_scalars>, arg=arg@entry=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:203
#9 0x00007f244e3e13ac in qsort_arg (a=0x7f24578f5348,
a@entry=0x7f2457816928, n=<optimized out>, n@entry=109083,
es=es@entry=16, cmp=cmp@entry=0x7f244e0d6af0 <compare_scalars>,
arg=arg@entry=0x7fffa958de70) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/port/qsort_arg.c:203
#10 0x00007f244e0d604f in compute_scalar_stats (stats=0x7f244fd168f8,
fetchfunc=<optimized out>, samplerows=110194, totalrows=110194) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/backend/commands/analyze.c:2378
#11 0x00007f244e0d76f9 in do_analyze_rel
(onerel=onerel@entry=0x7f244fc339d8, options=options@entry=99,
params=params@entry=0x7f244f98b9f0, va_cols=va_cols@entry=0x0,
acquirefunc=<optimized out>, relpages=11515, inh=0 '\000',
in_outer_xact=0 '\000', elevel=13) at
/build/postgresql-10-U6N320/postgresql-10-10.4/build/../src/backend/commands/analyze.c:545
After a bit of digging it became clear that they hit the libc bug:
https://sourceware.org/bugzilla/show_bug.cgi?id=18441
We decided to switch to libicu collation, but it became clear that
ANALYZE ignore column level COLLATE and stubbornly use default collation.
It happens thanks to this piece of code:
static void
compute_scalar_stats(VacAttrStatsP stats,
AnalyzeAttrFetchFunc fetchfunc,
int samplerows,
double totalrows)
....
/* We always use the default collation for statistics */
ssup.ssup_collation = DEFAULT_COLLATION_OID;
....
Ok, we decided to set libicu collation as default for database, although
it is a major pain.
But turns out it`s impossible to set libicu collation as default for
database:
postgres=# create database icu LC_COLLATE = 'en-x-icu';
ERROR: invalid locale name: "en-x-icu"
Why ANALYZE igrones column COLLATE? It there workaround to force ANALYZE
to use libicu?
--
Grigory Smolkin
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: long analyze, libc bug and libicu
@ 2018-07-07 07:10 Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
parent: Grigory Smolkin <g.smolkin@postgrespro.ru>
0 siblings, 1 reply; 6+ messages in thread
From: Peter Eisentraut @ 2018-07-07 07:10 UTC (permalink / raw)
To: Grigory Smolkin <g.smolkin@postgrespro.ru>; pgsql-bugs
On 05.07.18 17:05, Grigory Smolkin wrote:
> Why ANALYZE igrones column COLLATE?
I think the statistics would be mostly the same independent of which
collation you use. This could possibly be refined, but I don't think
it's a major problem right now.
--
Peter Eisentraut http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: long analyze, libc bug and libicu
@ 2018-07-07 09:18 Grigory Smolkin <g.smolkin@postgrespro.ru>
parent: Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
0 siblings, 2 replies; 6+ messages in thread
From: Grigory Smolkin @ 2018-07-07 09:18 UTC (permalink / raw)
To: pgsql-bugs@lists.postgresql.org, Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
On 07/07/2018 10:10 AM, Peter Eisentraut wrote:
> On 05.07.18 17:05, Grigory Smolkin wrote:
>> Why ANALYZE igrones column COLLATE?
> I think the statistics would be mostly the same independent of which
> collation you use. This could possibly be refined, but I don't think
> it's a major problem right now.
>
Thank you for your interest in this problem!
> I think the statistics would be mostly the same independent of which
> collation you use.
I assumed that one of the goals of using libicu is to be independent
from libc collation and it`s bugs and inconsistencies, but current
ANALYZE forced to use libc anyway, which undermines that goal.
> This could possibly be refined, but I don't think
> it's a major problem right now.
It`s a major problem to people, who use Thai alphabet.
In attachment there is a data sample(33MB on my machine). ANALYZE`ing it
comes up with following results:
postgres=# ANALYZE t_icu_coll;
ANALYZE
Time: 2252086.648 ms
37minutes on 33MB table is painful. On big tables autovacuum ANALYZE
goes for hours, starving autovacuum VACUUM for worker
slots(autovacuum_max_workers).
Another major problem is that in strol_l() backend process ignores
pg_terminate_backend()/pg_cancel_backend() functions.
With attached patch this problem goes away:
postgres=# analyze t_icu_coll;
ANALYZE
Time: 161.419 ms
--
Grigory Smolkin
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company
Attachments:
t_icu_coll.sql.gz (application/gzip, 3.2M) download
analyze_honour_column_collation.patch (text/x-patch, 674B) download
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index 848263d..88dda65 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -2291,8 +2291,12 @@ compute_scalar_stats(VacAttrStatsP stats,
memset(&ssup, 0, sizeof(ssup));
ssup.ssup_cxt = CurrentMemoryContext;
- /* We always use the default collation for statistics */
- ssup.ssup_collation = DEFAULT_COLLATION_OID;
+ /* Try to use column collation for statistics */
+ if (stats->attr->attcollation == InvalidOid)
+ ssup.ssup_collation = DEFAULT_COLLATION_OID;
+ else
+ ssup.ssup_collation = stats->attr->attcollation;
+
ssup.ssup_nulls_first = false;
/*
* Re: long analyze, libc bug and libicu
@ 2018-07-07 14:16 Stephen Frost <sfrost@snowman.net>
parent: Grigory Smolkin <g.smolkin@postgrespro.ru>
1 sibling, 0 replies; 6+ messages in thread
From: Stephen Frost @ 2018-07-07 14:16 UTC (permalink / raw)
To: Grigory Smolkin <g.smolkin@postgrespro.ru>; +Cc: pgsql-bugs@lists.postgresql.org, Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
Greetings,
* Grigory Smolkin (g.smolkin@postgrespro.ru) wrote:
> On 07/07/2018 10:10 AM, Peter Eisentraut wrote:
> >On 05.07.18 17:05, Grigory Smolkin wrote:
> >>Why ANALYZE igrones column COLLATE?
> >I think the statistics would be mostly the same independent of which
> >collation you use. This could possibly be refined, but I don't think
> >it's a major problem right now.
>
> Thank you for your interest in this problem!
>
> >I think the statistics would be mostly the same independent of which
> >collation you use.
>
> I assumed that one of the goals of using libicu is to be independent from
> libc collation and it`s bugs and inconsistencies, but current ANALYZE forced
> to use libc anyway, which undermines that goal.
I would have thought so too, especially in a case like you describe
below...
> > This could possibly be refined, but I don't think
> >it's a major problem right now.
>
> It`s a major problem to people, who use Thai alphabet.
> In attachment there is a data sample(33MB on my machine). ANALYZE`ing it
> comes up with following results:
>
> postgres=# ANALYZE t_icu_coll;
> ANALYZE
> Time: 2252086.648 ms
>
> 37minutes on 33MB table is painful. On big tables autovacuum ANALYZE goes
> for hours, starving autovacuum VACUUM for worker
> slots(autovacuum_max_workers).
> Another major problem is that in strol_l() backend process ignores
> pg_terminate_backend()/pg_cancel_backend() functions.
>
> With attached patch this problem goes away:
>
> postgres=# analyze t_icu_coll;
> ANALYZE
> Time: 161.419 ms
Wow, that's definitely an issue.
I haven't looked at the patch in any depth, but definitely a +1 from me
for figuring out how to fix this issue..
Thanks!
Stephen
Attachments:
signature.asc (application/pgp-signature, 818B) download
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: long analyze, libc bug and libicu
@ 2018-07-07 14:35 Tom Lane <tgl@sss.pgh.pa.us>
parent: Grigory Smolkin <g.smolkin@postgrespro.ru>
1 sibling, 0 replies; 6+ messages in thread
From: Tom Lane @ 2018-07-07 14:35 UTC (permalink / raw)
To: Grigory Smolkin <g.smolkin@postgrespro.ru>; +Cc: pgsql-bugs@lists.postgresql.org, Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
Grigory Smolkin <g.smolkin@postgrespro.ru> writes:
> On 07/07/2018 10:10 AM, Peter Eisentraut wrote:
>> On 05.07.18 17:05, Grigory Smolkin wrote:
>>> Why ANALYZE igrones column COLLATE?
>> I think the statistics would be mostly the same independent of which
>> collation you use. This could possibly be refined, but I don't think
>> it's a major problem right now.
I don't actually believe that the stats would be mostly the same.
Yes, we ought to arrive at the same MCV list, ndistinct, etc, but the
histogram depends critically on the sort order. In particular its
endpoints, and estimates for comparison values near the endpoints,
might be very much different.
However, this is something that was left for future research when
we added collations, and nobody's really followed up on that.
Should ANALYZE/the planner care about collation (perhaps only for
specific stats types)? Does that go as far as ignoring stats that don't
match the query operator's collation? Should we consider recording stats
for more than one collation, and if so which ones? What are the
backwards-compatibility issues involved in changing something like this?
Grigory's proposal amounts to assuming that the column's assigned
collation is the only one of interest, which might be true but it
needs some defense. In any case it wouldn't end up being a three-line
patch; there's a whole lot of downstream work to consider.
But besides that, I've got no sympathy for forcing through a change
in this area just on the grounds that some platform's strcoll_l is
ridiculously slow with certain collations. The right answer for that
is to lobby the libc maintainers to fix strcoll_l, especially since
the odds of us changing this in released branches are nil.
regards, tom lane
^ permalink raw reply [nested|flat] 6+ messages in thread
* [PATCH v2] PQsendQuery: Don't send Close in pipeline mode
@ 2022-06-15 17:56 Alvaro Herrera <alvherre@alvh.no-ip.org>
0 siblings, 0 replies; 6+ messages in thread
From: Alvaro Herrera @ 2022-06-15 17:56 UTC (permalink / raw)
In commit 4efcf47053ea, we modified PQsendQuery to send a Close message
when in pipeline mode. But now we discover that that's not a good
thing: under certain circumstances, it causes the server to deliver a
CloseComplete message at a time when the client is not expecting it. We
failed to noticed it because the tests don't have any scenario where the
problem is hit. Remove the offending Close, and add a test case that
tickles the problematic scenario.
Co-authored-by: Kyotaro Horiguchi <horikyota.ntt@gmail.com>
Reported-by: Daniele Varrazzo <daniele.varrazzo@gmail.com>
Discussion: https://postgr.es/m/CA+mi_8bvD0_CW3sumgwPvWdNzXY32itoG_16tDYRu_1S2gV2iw@mail.gmail.com
---
src/interfaces/libpq/fe-exec.c | 5 --
.../modules/libpq_pipeline/libpq_pipeline.c | 62 +++++++++++++++++++
.../traces/pipeline_abort.trace | 2 -
.../traces/simple_pipeline.trace | 12 ++++
4 files changed, 74 insertions(+), 7 deletions(-)
diff --git a/src/interfaces/libpq/fe-exec.c b/src/interfaces/libpq/fe-exec.c
index 4180683194..e2df3a3480 100644
--- a/src/interfaces/libpq/fe-exec.c
+++ b/src/interfaces/libpq/fe-exec.c
@@ -1403,11 +1403,6 @@ PQsendQueryInternal(PGconn *conn, const char *query, bool newQuery)
pqPutInt(0, 4, conn) < 0 ||
pqPutMsgEnd(conn) < 0)
goto sendFailed;
- if (pqPutMsgStart('C', conn) < 0 ||
- pqPutc('P', conn) < 0 ||
- pqPuts("", conn) < 0 ||
- pqPutMsgEnd(conn) < 0)
- goto sendFailed;
entry->queryclass = PGQUERY_EXTENDED;
entry->query = strdup(query);
diff --git a/src/test/modules/libpq_pipeline/libpq_pipeline.c b/src/test/modules/libpq_pipeline/libpq_pipeline.c
index c27c4e0ada..e24fbfe1cc 100644
--- a/src/test/modules/libpq_pipeline/libpq_pipeline.c
+++ b/src/test/modules/libpq_pipeline/libpq_pipeline.c
@@ -968,15 +968,29 @@ test_prepared(PGconn *conn)
fprintf(stderr, "ok\n");
}
+/* Notice processor: print them, and count how many we got */
+static void
+notice_processor(void *arg, const char *message)
+{
+ int *n_notices = (int *) arg;
+
+ (*n_notices)++;
+ fprintf(stderr, "NOTICE %d: %s", *n_notices, message);
+}
+
static void
test_simple_pipeline(PGconn *conn)
{
PGresult *res = NULL;
const char *dummy_params[1] = {"1"};
Oid dummy_param_oids[1] = {INT4OID};
+ PQnoticeProcessor oldproc;
+ int n_notices = 0;
fprintf(stderr, "simple pipeline... ");
+ oldproc = PQsetNoticeProcessor(conn, notice_processor, &n_notices);
+
/*
* Enter pipeline mode and dispatch a set of operations, which we'll then
* process the results of as they come in.
@@ -1052,6 +1066,54 @@ test_simple_pipeline(PGconn *conn)
if (PQpipelineStatus(conn) != PQ_PIPELINE_OFF)
pg_fatal("Exiting pipeline mode didn't seem to work");
+ if (n_notices > 0)
+ pg_fatal("unexpected notice");
+
+ /* Try the same thing with PQsendQuery */
+ if (PQenterPipelineMode(conn) != 1)
+ pg_fatal("failed to enter pipeline mode: %s", PQerrorMessage(conn));
+
+ if (PQsendQuery(conn, "SELECT 1") != 1)
+ pg_fatal("failed to send query: %s", PQerrorMessage(conn));
+ PQsendFlushRequest(conn);
+ res = PQgetResult(conn);
+ if (res == NULL)
+ pg_fatal("PQgetResult returned null when there's a pipeline item: %s",
+ PQerrorMessage(conn));
+ if (PQresultStatus(res) != PGRES_TUPLES_OK)
+ pg_fatal("Unexpected result code %s from first pipeline item",
+ PQresStatus(PQresultStatus(res)));
+ PQclear(res);
+
+ res = PQgetResult(conn);
+ if (res != NULL)
+ pg_fatal("expected NULL result");
+
+ if (PQpipelineSync(conn) != 1)
+ pg_fatal("pipeline sync failed: %s", PQerrorMessage(conn));
+ res = PQgetResult(conn);
+ if (res == NULL)
+ pg_fatal("PQgetResult returned null when there's a pipeline item: %s",
+ PQerrorMessage(conn));
+ if (PQresultStatus(res) != PGRES_PIPELINE_SYNC)
+ pg_fatal("Unexpected result code %s instead of PGRES_PIPELINE_SYNC, error: %s",
+ PQresStatus(PQresultStatus(res)), PQerrorMessage(conn));
+ PQclear(res);
+ res = NULL;
+
+ if (PQexitPipelineMode(conn) != 1)
+ pg_fatal("attempt to exit pipeline mode failed when it should've succeeded: %s",
+ PQerrorMessage(conn));
+
+ /*
+ * Must not have got any notices here; note bug as described in
+ * https://postgr.es/m/CA+mi_8bvD0_CW3sumgwPvWdNzXY32itoG_16tDYRu_1S2gV2iw@mail.gmail.com
+ */
+ if (n_notices > 0)
+ pg_fatal("got %d notice(s)", n_notices);
+
+ PQsetNoticeProcessor(conn, oldproc, NULL);
+
fprintf(stderr, "ok\n");
}
diff --git a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace
index 3fce548b99..254e485997 100644
--- a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace
+++ b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace
@@ -38,7 +38,6 @@ F 26 Parse "" "SELECT 1; SELECT 2" 0
F 12 Bind "" "" 0 0 0
F 6 Describe P ""
F 9 Execute "" 0
-F 6 Close P ""
F 4 Sync
B NN ErrorResponse S "ERROR" V "ERROR" C "42601" M "cannot insert multiple commands into a prepared statement" F "SSSS" L "SSSS" R "SSSS" \x00
B 5 ReadyForQuery I
@@ -46,7 +45,6 @@ F 54 Parse "" "SELECT 1.0/g FROM generate_series(3, -1, -1) g" 0
F 12 Bind "" "" 0 0 0
F 6 Describe P ""
F 9 Execute "" 0
-F 6 Close P ""
F 4 Sync
B 4 ParseComplete
B 4 BindComplete
diff --git a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace
index 5c94749bc1..349034dda6 100644
--- a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace
+++ b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace
@@ -9,4 +9,16 @@ B 33 RowDescription 1 "?column?" NNNN 0 NNNN 4 -1 0
B 11 DataRow 1 1 '1'
B 13 CommandComplete "SELECT 1"
B 5 ReadyForQuery I
+F 16 Parse "" "SELECT 1" 0
+F 12 Bind "" "" 0 0 0
+F 6 Describe P ""
+F 9 Execute "" 0
+F 4 Flush
+B 4 ParseComplete
+B 4 BindComplete
+B 33 RowDescription 1 "?column?" NNNN 0 NNNN 4 -1 0
+B 11 DataRow 1 1 '1'
+B 13 CommandComplete "SELECT 1"
+F 4 Sync
+B 5 ReadyForQuery I
F 4 Terminate
--
2.30.2
--eq2sy33kqql2cp67--
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2022-06-15 17:56 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2018-07-05 15:05 long analyze, libc bug and libicu Grigory Smolkin <g.smolkin@postgrespro.ru>
2018-07-07 07:10 ` Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
2018-07-07 09:18 ` Grigory Smolkin <g.smolkin@postgrespro.ru>
2018-07-07 14:16 ` Stephen Frost <sfrost@snowman.net>
2018-07-07 14:35 ` Tom Lane <tgl@sss.pgh.pa.us>
2022-06-15 17:56 [PATCH v2] PQsendQuery: Don't send Close in pipeline mode Alvaro Herrera <alvherre@alvh.no-ip.org>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox