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.kuzmenkov@postgrespro.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