On Tue, Sep 24, 2013 at 5:16 AM, Robert Haas <robertmh...@gmail.com> wrote:
> On Fri, Sep 20, 2013 at 11:28 PM, David Rowley <dgrowle...@gmail.com> > wrote:\ > > I put the above results into the attached spreadsheet. On my intel i5 > laptop > > I'm seeing a slow down of about 1 second per million queries for the > longer > > log_line_prefix and about 1 second per 5 million queries with the shorter > > log_line_prefix. > > > > In the attached spreadsheet I've mocked up some very rough estimates on > the > > performance cost of this change. I think a while ago I read about a > > benchmark Robert ran on a 64 core machine which ran around 400k > transactions > > per second. I've included some workings in the spreadsheet to show how > this > > change would affect that benchmark, but I have assumed that the hardware > > would only be able to execute the log_line_prefix function at the same > speed > > as my i5 laptop. With this very worst case estimates my calculations say > > that the performance hit is 0.6% with the log_line_prefix which contains > all > > of the variables and 0.11% for the shorter log_line_prefix. I would > imagine > > that the hardware that performed 400k TPS would be able to run > > log_line_prefix faster than my 3 year old i5 laptop, so this is likely > quite > > a big over estimation of the hit. > > Well, on those tests, I was hardly logging anything, so it's hard to > really draw any conclusions that way. > > I think the real concern with this patch, performance-wise, is what > happens in environments where there is a lot of logging going on. > We've had previous reports of people who can't even enable the logging > they want because the performance cost is unacceptably high. That's > why we added that logging hook in 9.2 or 9.3, so that people can write > alternative loggers that just throw away messages if the recipient > can't eat them fast enough. > > I wouldn't be keen to accept a 25% performance hit on logging overall, > but log_line_prefix() is only a small part of that cost. > > So... I guess the question that I'd ask is, if you write a PL/pgsql > function that does RAISE NOTICE in a loop a large number of times, can > you measure any difference in how fast that function executes on the > patch and unpatched code? If so, how much? > > Ok, I've been doing a bit of benchmarking on this. To mock up a really fast I/O system I created a RAM disk which I will ask Postgres to send the log files to. mkdir /tmp/ramdisk; chmod 777 /tmp/ramdisk mount -t tmpfs -o size=256M tmpfs /tmp/ramdisk/ I created the following function in plpgsql create function stresslog(n int) returns int as $$ begin while n > 0 loop raise notice '%', n; n := n - 1; end loop; return 0; end; $$ language plpgsql; I was running postgreql with david@ubuntu64:~/9.4/bin$ ./pg_ctl start -D /home/david/9.4/data -l /tmp/ramdisk/pg.log I ran the following command 5 times for each version. client_min_message is set to warning and log_min_message is set to notice postgres=# select stresslog(100000); stresslog ----------- 0 (1 row) I do see a 15-18% slow down with the patched version, so perhaps I'll need to look to see if I can speed it up a bit, although I do feel this benchmark is not quite a normal workload. Please see below the results, or if you want to play about with them a bit, please use the attached spreadsheet. ------------------------------------ * Round 1 Patched: log_line_prefix = "%a %u %d %r %h %p %t %m %i %e %c %l %s %v %x " Time: 1822.105 ms Time: 1762.529 ms Time: 1839.724 ms Time: 1837.372 ms Time: 1813.240 ms unpatched: log_line_prefix = "%a %u %d %r %h %p %t %m %i %e %c %l %s %v %x " Time: 1519.032 ms Time: 1528.760 ms Time: 1484.074 ms Time: 1552.786 ms Time: 1569.410 ms * Round 2 patched: log_line_prefix = "%a %u %d %e " Time: 625.969 ms Time: 668.444 ms Time: 648.310 ms Time: 663.655 ms Time: 715.397 ms unpatched: log_line_prefix = "%a %u %d %e " Time: 598.146 ms Time: 518.827 ms Time: 532.858 ms Time: 529.584 ms Time: 537.276 ms Regards David Rowley
log_line_prefix_benchmark_stresslog_v0.4.xls
Description: MS-Excel spreadsheet
-- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers