Re: Allowing printf("%m") only where it actually works - Mailing list pgsql-hackers

I wrote:
> ... So we would be taking a hit on most platforms, but I've not really
> seen sprintf as a major component of very many profiles.  Moreover,
> at least for the elog/ereport use-case, we'd be buying back some
> nontrivial part of that hit by getting rid of expand_fmt_string().
> Also worth noting is that we've never made any effort at all to
> micro-optimize snprintf.c, so maybe there's some gold to be mined
> there to reduce the penalty.

Oh, the plot thickens: apparently, a very large chunk of the time
in that test scenario went into the %g format item, which I think
we can all agree isn't performance-critical for Postgres.  Changing
the test case to test %lld in place of %g, I get (on the same
five platforms as before)

RHEL6:

snprintf time = 357.634 ms total, 0.000357634 ms per iteration
pg_snprintf time = 281.708 ms total, 0.000281708 ms per iteration
ratio = 0.788

macOS:

snprintf time = 155.86 ms total, 0.00015586 ms per iteration
pg_snprintf time = 104.074 ms total, 0.000104074 ms per iteration
ratio = 0.668

FreeBSD:

snprintf time = 268.883 ms total, 0.000268883 ms per iteration
pg_snprintf time = 185.294 ms total, 0.000185294 ms per iteration
ratio = 0.689

OpenBSD:

snprintf time = 276.418 ms total, 0.000276418 ms per iteration
pg_snprintf time = 153.334 ms total, 0.000153334 ms per iteration
ratio = 0.555

NetBSD:

snprintf time = 1174.13 ms total, 0.00117413 ms per iteration
pg_snprintf time = 1508.82 ms total, 0.00150882 ms per iteration
ratio = 1.285

So there's actually a plausible argument to be made that we'd
get a net speed win on most platforms and test cases.

            regards, tom lane

#include "postgres_fe.h"

#include "portability/instr_time.h"

#include "snprintf.c"

int
main(int argc, char **argv)
{
    int count = 0;
    char buffer[1000];
    instr_time    start;
    instr_time    stop;
    double elapsed;
    double elapsed2;
    int i;

    if (argc > 1)
        count = atoi(argv[1]);
    if (count <= 0)
        count = 1000000;

    INSTR_TIME_SET_CURRENT(start);

    for (i = 0; i < count; i++)
    {
        snprintf(buffer, sizeof(buffer),
                 "%d %lld %s",
                 42, (long long) 42,

"01234567890012345678900123456789001234567890012345678900123456789001234567890012345678900123456789001234567890");
    }

    INSTR_TIME_SET_CURRENT(stop);
    INSTR_TIME_SUBTRACT(stop, start);
    elapsed = INSTR_TIME_GET_MILLISEC(stop);

    printf("snprintf time = %g ms total, %g ms per iteration\n",
           elapsed, elapsed / count);

    INSTR_TIME_SET_CURRENT(start);

    for (i = 0; i < count; i++)
    {
        pg_snprintf(buffer, sizeof(buffer),
                 "%d %lld %s",
                 42, (long long) 42,

"01234567890012345678900123456789001234567890012345678900123456789001234567890012345678900123456789001234567890");
    }

    INSTR_TIME_SET_CURRENT(stop);
    INSTR_TIME_SUBTRACT(stop, start);
    elapsed2 = INSTR_TIME_GET_MILLISEC(stop);

    printf("pg_snprintf time = %g ms total, %g ms per iteration\n",
           elapsed2, elapsed2 / count);
    printf("ratio = %.3f\n", elapsed2 / elapsed);

    return 0;
}