Received: from maia.hub.org (maia-3.hub.org [200.46.204.243]) by mail.postgresql.org (Postfix) with ESMTP id 1A700B5DBE1 for ; Fri, 24 Jun 2011 20:26:42 -0300 (ADT) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.243]) (amavisd-maia, port 10024) with ESMTP id 85378-05 for ; Fri, 24 Jun 2011 23:26:35 +0000 (UTC) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from moutng.kundenserver.de (moutng.kundenserver.de [212.227.17.9]) by mail.postgresql.org (Postfix) with ESMTP id 477B9B5D803 for ; Fri, 24 Jun 2011 20:26:35 -0300 (ADT) Received: from [192.168.1.7] (mail.highperformancepostgresql.com [71.179.240.8]) by mrelayeu.kundenserver.de (node=mrbap0) with ESMTP (Nemesis) id 0LpPm9-1RCajN2bTB-00fc1U; Sat, 25 Jun 2011 01:26:33 +0200 Message-ID: <4E051D27.8080100@2ndQuadrant.com> Date: Fri, 24 Jun 2011 19:26:31 -0400 From: Greg Smith User-Agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.16) Gecko/20110505 Icedove/3.0.11 MIME-Version: 1.0 To: sthomas@peak6.com CC: pgsql-performance@postgresql.org Subject: Re: Cost of creating an emply WAL segment References: <1308926594.2656.210.camel@lenovo01-laptop03.gunduz.org> <4E04B8E9.3030707@2ndQuadrant.com> <4E04DDB3.8050306@peak6.com> In-Reply-To: <4E04DDB3.8050306@peak6.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit X-Provags-ID: V02:K0:Iv/9dLrarPp0NTGq/aeNclojTjTlCHdBM2OduTtAueO X0/0FhisbwWp9UXRMMl5F6lGcA1o2IV92uCkhhTx8v4D5+28/3 Frtbp0lc6aPf3TUL+arsbL/d9CQxG390E8XbYrWAG0QvWx+bXy Y+g/J6g8oJAE5qiuF1WNQxRG6eqhJRzITh6cGqOzFglZiZiQYd V4J6AqtKKw95FYSBRHuTbvJVE5G8xPVtcxz/cN+Fnk= X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=-1.9 tagged_above=-10 required=5 tests=BAYES_00=-1.9, RCVD_IN_DNSWL_NONE=-0.0001 X-Spam-Level: X-Archive-Number: 201106/238 X-Sequence-Number: 44171 On 06/24/2011 02:55 PM, Shaun Thomas wrote: > On 06/24/2011 11:18 AM, Greg Smith wrote: > >> sync=14525.296 s, total=14786.868 s > > Whaaaaaaaaat!? 6% of 8GB is just shy of 500MB. That's not a small > amount, exactly, but it took 14525 seconds to call syncs for those > writes? What kind of ridiculous IO would cause something like that? > That's even way beyond an OS-level dirty buffer flush on a massive > system. Wow! It is in fact smaller than the write cache on the disk array involved. The mystery is explained at http://projects.2ndquadrant.it/sites/default/files/WriteStuff-PGCon2011.pdf The most relevant part: -Background writer stop working normally while running sync -Never pauses to fully consume the fsync queues backends fill -Once filled, all backend writes do their own fsync -Serious competition for the checkpoint writes When the background writer's fsync queue fills, and you have 100 clients all doing their own writes and making an fsync call after each one of them (the case on this server), the background writer ends up only getting around 1/100 of the I/O capabilities of the server available in its time slice. And that's how a sync phase that might normally take two minutes on a really busy server ends up running for hours instead. The improvement in 9.1 gets the individual backends involved in trying to compact the fsync queue when they discover it is full, which seems to make the worst case behavior here much better. -- Greg Smith 2ndQuadrant US greg@2ndQuadrant.com Baltimore, MD PostgreSQL Training, Services, and 24x7 Support www.2ndQuadrant.us "PostgreSQL 9.0 High Performance": http://www.2ndQuadrant.com/books