Re: Performance improvements for src/port/snprintf.c

On 2018-09-26 15:04:20 -0700, Andres Freund wrote:
> On 2018-09-12 14:14:15 -0400, Tom Lane wrote:
> > Alexander Kuzmenkov <a(dot)kuzmenkov(at)postgrespro(dot)ru> writes:
> > > I benchmarked this, using your testbed and comparing to libc sprintf
> > > (Ubuntu GLIBC 2.27-0ubuntu3) and another implementation I know [1], all
> > > compiled with gcc 5.
> >
> > Thanks for reviewing!
> >
> > The cfbot noticed that the recent dlopen patch conflicted with this in
> > configure.in, so here's a rebased version. The code itself didn't change.
>
> Conflicts again, but not too hard to resolve.
>
> The mini benchmark from http://archives.postgresql.org/message-id/20180926174645.nsyj77lx2mvtz4kx%40alap3.anarazel.de
> is significantly improved by this patch.
>
> > 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)
>
> This patch:
>
> postgres[32704][1]=# ;SELECT pg_prewarm('somefloats');COPY somefloats TO '/dev/null';
> Time: 0.269 ms
> ┌────────────┐
> │ pg_prewarm │
> ├────────────┤
> │ 73530 │
> └────────────┘
> (1 row)
>
> Time: 34.983 ms
> COPY 10000000
> Time: 15511.478 ms (00:15.511)
>
>
> The profile from 96bf88d52711ad3a0a4cc2d1d9cb0e2acab85e63^ is:
> + 38.15% postgres libc-2.27.so [.] __GI___printf_fp_l
> + 13.98% postgres libc-2.27.so [.] hack_digit
> + 7.54% postgres libc-2.27.so [.] __mpn_mul_1
> + 7.32% postgres postgres [.] CopyOneRowTo
> + 6.12% postgres libc-2.27.so [.] vfprintf
> + 3.14% postgres libc-2.27.so [.] __strlen_avx2
> + 1.97% postgres postgres [.] heap_deform_tuple
> + 1.77% postgres postgres [.] AllocSetAlloc
> + 1.43% postgres postgres [.] psprintf
> + 1.25% postgres libc-2.27.so [.] _IO_str_init_static_internal
> + 1.09% postgres libc-2.27.so [.] _IO_vsnprintf
> + 1.09% postgres postgres [.] appendBinaryStringInfo
>
> The profile of master with this patch is:
>
> + 32.38% postgres libc-2.27.so [.] __GI___printf_fp_l
> + 11.08% postgres libc-2.27.so [.] hack_digit
> + 9.55% postgres postgres [.] CopyOneRowTo
> + 6.24% postgres libc-2.27.so [.] __mpn_mul_1
> + 5.01% postgres libc-2.27.so [.] vfprintf
> + 4.91% postgres postgres [.] dopr.constprop.4
> + 3.53% postgres libc-2.27.so [.] __strlen_avx2
> + 1.55% postgres libc-2.27.so [.] __strchrnul_avx2
> + 1.49% postgres libc-2.27.so [.] __memmove_avx_unaligned_erms
> + 1.35% postgres postgres [.] AllocSetAlloc
> + 1.32% postgres libc-2.27.so [.] _IO_str_init_static_internal
> + 1.30% postgres postgres [.] FunctionCall1Coll
> + 1.27% postgres postgres [.] psprintf
> + 1.16% postgres postgres [.] appendBinaryStringInfo
> + 1.16% postgres libc-2.27.so [.] _IO_old_init
> + 1.06% postgres postgres [.] heap_deform_tuple
> + 1.02% postgres libc-2.27.so [.] sprintf
> + 1.02% postgres libc-2.27.so [.] _IO_vsprintf
>
> (all functions above 1%)
>
>
> I assume this partially is just the additional layers of function calls
> (psprintf, pvsnprintf, pg_vsnprintf, dopr) that are now done, in
> addition to pretty much the same work as before (i.e. sprintf("%.*f")).

I'm *NOT* proposing that as the actual solution, but as a datapoint, it
might be interesting that hardcoding the precision and thus allowing use
ofusing strfromd() instead of sprintf yields a *better* runtime than
master.

Time: 10255.134 ms (00:10.255)

Greetings,

Andres Freund