Re: Allowing printf("%m") only where it actually works

Andres Freund <andres@anarazel.de>

From: Andres Freund <andres@anarazel.de>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: Michael Paquier <michael@paquier.xyz>, Thomas Munro <thomas.munro@enterprisedb.com>, Alvaro Herrera <alvherre@2ndquadrant.com>, PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>
Date: 2018-09-26T17:46:45Z
Lists: pgsql-hackers
Hi,

On 2018-09-24 13:18:47 -0400, Tom Lane wrote:
> 0002 changes things so that we always use our snprintf, removing all the
> configure logic associated with that.

In the commit message you wrote:

> Preliminary performance testing suggests that as it stands, snprintf.c is
> faster than the native printf functions for some tasks on some platforms,
> and slower for other cases.  A pending patch will improve that, though
> cases with floating-point conversions will doubtless remain slower unless
> we want to put a *lot* of effort into that.  Still, we've not observed
> that *printf is really a performance bottleneck for most workloads, so
> I doubt this matters much.

I severely doubt the last sentence. I've *many* times seen *printf be a
significant bottleneck. In particular just about any pg_dump of a
database that has large tables with even just a single float column is
commonly bottlenecked on float -> string conversion.

A trivial bad benchmark:

CREATE TABLE somefloats(id serial, data1 float8, data2 float8, data3 float8);
INSERT INTO somefloats(data1, data2, data3) SELECT random(), random(), random() FROM generate_series(1, 10000000);
VACUUM FREEZE somefloats;


postgres[12850][1]=# \dt+ somefloats
                       List of relations
┌────────┬────────────┬───────┬────────┬────────┬─────────────┐
│ Schema │    Name    │ Type  │ Owner  │  Size  │ Description │
├────────┼────────────┼───────┼────────┼────────┼─────────────┤
│ public │ somefloats │ table │ andres │ 575 MB │             │
└────────┴────────────┴───────┴────────┴────────┴─────────────┘

96bf88d52711ad3a0a4cc2d1d9cb0e2acab85e63:

COPY somefloats TO '/dev/null';
COPY 10000000
Time: 24575.770 ms (00:24.576)

96bf88d52711ad3a0a4cc2d1d9cb0e2acab85e63^:

COPY somefloats TO '/dev/null';
COPY 10000000
Time: 12877.037 ms (00:12.877)

IOW, we regress copy performance by about 2x. And one int and three
floats isn't a particularly insane table layout.


I'm not saying we shouldn't default to our printf - in fact I think we
probably past due to use a faster float->string conversion than we
portably get from the OS - but I don't think we can default to our
sprintf without doing something about the float conversion performance.


Greetings,

Andres Freund


Commits

  1. In pg_log_generic(), be more paranoid about preserving errno.

  2. Make src/common/exec.c's error logging less ugly.

  3. Select appropriate PG_PRINTF_ATTRIBUTE for recent NetBSD.

  4. Fix detection of the result type of strerror_r().

  5. Try another way to detect the result type of strerror_r().

  6. Clean up *printf macros to avoid conflict with format archetypes.

  7. Fix link failures due to snprintf/strerror changes.

  8. Implement %m in src/port/snprintf.c, and teach elog.c to rely on that.

  9. Always use our own versions of *printf().

  10. Incorporate strerror_r() into src/port/snprintf.c, too.

  11. Convert elog.c's useful_strerror() into a globally-used strerror wrapper.

  12. Revert "Distinguish printf-like functions that support %m from those that don't."

  13. Produce compiler errors if errno is referenced inside elog/ereport calls.

  14. Distinguish printf-like functions that support %m from those that don't.

  15. Fix unportable usage of printf("%m").

  16. Be more robust when strerror() doesn't give a useful result.