Re: Performance improvements for src/port/snprintf.c - Mailing list pgsql-hackers

From Tom Lane
Subject Re: Performance improvements for src/port/snprintf.c
Date
Msg-id 26193.1538582367@sss.pgh.pa.us
Whole thread Raw
In response to Re: Performance improvements for src/port/snprintf.c  (Tom Lane <tgl@sss.pgh.pa.us>)
Responses Re: Performance improvements for src/port/snprintf.c  (Andres Freund <andres@anarazel.de>)
List pgsql-hackers
I wrote:
> ... However, I did add recent glibc (Fedora 28)
> to the mix, and I was interested to discover that they seem to have
> added a fast-path for format strings that are exactly "%s", just as
> NetBSD did.  I wonder if we should reconsider our position on doing
> that.  It'd be a simple enough addition...

I experimented with adding an initial check for "format is exactly %s"
at the top of dopr(), and couldn't get excited about that.  Instrumenting
things showed that the optimization fired in only 1.8% of the calls
during a run of our core regression tests.  Now, that might not count
as a really representative workload, but it doesn't make me think that
the case is worth optimizing for us.

But then it occurred to me that there's more than one way to skin this
cat.  We could, for an even cheaper extra test, detect that any one
format specifier is just "%s", and use the same kind of fast-path
within the loop.  With the same sort of instrumentation, I found that
a full 45% of the format specs executed in the core regression tests
are just %s.  That makes me think that a patch along the lines of the
attached is a good win for our use-cases.  Comparing to Fedora 28's
glibc, this gets us to

Test case: %s
snprintf time = 8.83615 ms total, 8.83615e-06 ms per iteration
pg_snprintf time = 23.9372 ms total, 2.39372e-05 ms per iteration
ratio = 2.709

Test case: %sx
snprintf time = 59.4481 ms total, 5.94481e-05 ms per iteration
pg_snprintf time = 29.8983 ms total, 2.98983e-05 ms per iteration
ratio = 0.503

versus what we have as of this morning's commit:

Test case: %s
snprintf time = 7.7427 ms total, 7.7427e-06 ms per iteration
pg_snprintf time = 26.2439 ms total, 2.62439e-05 ms per iteration
ratio = 3.390

Test case: %sx
snprintf time = 61.4452 ms total, 6.14452e-05 ms per iteration
pg_snprintf time = 32.7516 ms total, 3.27516e-05 ms per iteration
ratio = 0.533

The penalty for non-%s cases seems to be a percent or so, although
it's barely above the noise floor in my tests.

            regards, tom lane

diff --git a/src/port/snprintf.c b/src/port/snprintf.c
index cad7345..b9b6add 100644
*** a/src/port/snprintf.c
--- b/src/port/snprintf.c
*************** dopr(PrintfTarget *target, const char *f
*** 431,436 ****
--- 431,449 ----

          /* Process conversion spec starting at *format */
          format++;
+
+         /* Fast path for conversion spec that is exactly %s */
+         if (*format == 's')
+         {
+             format++;
+             strvalue = va_arg(args, char *);
+             Assert(strvalue != NULL);
+             dostr(strvalue, strlen(strvalue), target);
+             if (target->failed)
+                 break;
+             continue;
+         }
+
          fieldwidth = precision = zpad = leftjust = forcesign = 0;
          longflag = longlongflag = pointflag = 0;
          fmtpos = accum = 0;

pgsql-hackers by date:

Previous
From: David Fetter
Date:
Subject: Re: Early WIP/PoC for inlining CTEs
Next
From: Tom Lane
Date:
Subject: Re: Performance improvements for src/port/snprintf.c