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

From: Andres Freund <andres(at)anarazel(dot)de>
To: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: Alexander Kuzmenkov <a(dot)kuzmenkov(at)postgrespro(dot)ru>, pgsql-hackers(at)lists(dot)postgresql(dot)org
Subject: Re: Performance improvements for src/port/snprintf.c
Date: 2018-09-26 22:04:20
Message-ID: 20180926220419.lorxpb564gakdjkz@alap3.anarazel.de
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

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")).

- Andres

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Andres Freund 2018-09-26 22:18:14 Re: Performance improvements for src/port/snprintf.c
Previous Message Andres Freund 2018-09-26 21:49:53 Re: Allowing printf("%m") only where it actually works