Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.80) (envelope-from ) id 1YV4Bf-0004vG-Se for pgsql-admin@arkaria.postgresql.org; Mon, 09 Mar 2015 20:22:04 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.80) (envelope-from ) id 1YV4Be-0005q3-Q7 for pgsql-admin@arkaria.postgresql.org; Mon, 09 Mar 2015 20:22:02 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:DHE_RSA_AES_256_CBC_SHA256:256) (Exim 4.80) (envelope-from ) id 1YV4Bd-0005pw-7E for pgsql-admin@postgresql.org; Mon, 09 Mar 2015 20:22:01 +0000 Received: from mail-yh0-x22c.google.com ([2607:f8b0:4002:c01::22c]) by makus.postgresql.org with esmtps (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.80) (envelope-from ) id 1YV4BZ-0004Jn-1F for pgsql-admin@postgresql.org; Mon, 09 Mar 2015 20:21:59 +0000 Received: by yhaf10 with SMTP id f10so9187599yha.10 for ; Mon, 09 Mar 2015 13:21:55 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=message-id:date:from:user-agent:mime-version:to:subject:references :in-reply-to:content-type; bh=8kUs6VUx69EmHCFwy8qfDQrJrfNGKUQ8qDvzLqrBLiI=; b=kiQvCHtulaTZ5ylCTeovUr5pzS3ny/fRT+ZyquHzgJ04Vla8I2budPApprrrnjugGV Laitx4exULriFhWKorbpfLsuqenfWEgMmiqWPpwunD4Z3E6k/WcDaIGPftoI0x86tAv+ 5s5LteBZLDKHzV/uewZjID8Eyx+vVdciKkFO9BkfvBtn2yebKAC5XD/VE/Ui3xiiK83g jkXQkyr2Z05P5a0RigeplwSm36qQLwMUpAUSc+h4eguklGQMvqt5ZzqSnUkzf3I/2Luu DJON29FkpxdIsuUDxACwWWHv2u/PA07JfuKkJF3Ytzo+MWTi427kQsaxYbAkCTiaSzHI PXpA== X-Received: by 10.236.105.227 with SMTP id k63mr28602843yhg.100.1425932515830; Mon, 09 Mar 2015 13:21:55 -0700 (PDT) Received: from [192.168.254.3] (h77.89.102.166.static.ip.windstream.net. [166.102.89.77]) by mx.google.com with ESMTPSA id 54sm17040766yho.51.2015.03.09.13.21.54 (version=TLSv1.2 cipher=ECDHE-RSA-AES128-GCM-SHA256 bits=128/128); Mon, 09 Mar 2015 13:21:55 -0700 (PDT) Message-ID: <54FE00DE.50205@gmail.com> Date: Mon, 09 Mar 2015 16:21:50 -0400 From: John Scalia User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:31.0) Gecko/20100101 Thunderbird/31.5.0 MIME-Version: 1.0 To: Mark Steben , pgsql-admin Subject: Re: pgstat wait timeout encountered References: In-Reply-To: Content-Type: multipart/alternative; boundary="------------090608030903040800090304" X-Pg-Spam-Score: -2.7 (--) List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-admin Precedence: bulk Sender: pgsql-admin-owner@postgresql.org This is a multi-part message in MIME format. --------------090608030903040800090304 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Not to sound stupid, but two possible issues: 1) this is a really big table and 2) you have no index on the field "datname" Possible? Jay On 3/9/2015 3:50 PM, Mark Steben wrote: > Good afternoon, > > We have been sporadically receiving a warning: /pgstat wait timeout / > in our production environment. This has been always immediately follow= ed by > a successful execution of the query. > > EX: > =20 > Mar 6 00:31:29 ardbc01 postgres[42903]: [3-1] mavmail@10.93.156.42:pri= me_production:0WARNING: pgstat wait timeout > Mar 6 00:31:29 ardbc01 postgres[42903]: [3-2] mavmail@10.93.156.42:pri= me_production:0STATEMENT: SELECT * FROM pg_stat_database WHERE datname=3D= 'prime_production'; > Mar 6 00:31:29 ardbc01 postgres[42903]: [4-1] mavmail@10.93.156.42:pri= me_production:0LOG: duration: 10137.143 ms statement: SELECT * FROM pg_= stat_database WHERE > datname=3D'prime_production'; > > and > > mavmail@10.93.156.42:prime_production:0WARNING: pgstat wait timeout > Mar 6 00:31:46 ardbc01 postgres[42903]: [6-2] mavmail@10.93.156.42:pri= me_production:0STATEMENT: SELECT SUM(idx_blks_hit) AS hits, SUM(idx_blks= _read) AS reads FROM > pg_statio_user_indexes > Mar 6 00:31:46 ardbc01 postgres[42903]: [7-1] mavmail@10.93.156.42:pri= me_production:0LOG: duration: 10144.601 ms statement: SELECT SUM(idx_bl= ks_hit) AS hits, > SUM(idx_blks_read) AS reads FROM pg_statio_user_indexes > > This is not confined to queries of pg stat infrastructure tables. In an= other database we can receive the same warning on a vacuum: > > mavmail@10.93.156.45:mavmail WARNING: pgstat wait timeout > Mar 6 01:16:44 ardbc01 postgres[66365]: [12-2] mavmail@10.93.156.45:ma= vmail STATEMENT: VACUUM VERBOSE ANALYZE update_queues; > Mar 6 01:16:44 ardbc01 postgres[66365]: [13-1] mavmail@10.93.156.45:ma= vmail INFO: vacuuming "public.update_queues" > Mar 6 01:16:44 ardbc01 postgres[66365]: [13-2] mavmail@10.93.156.45:ma= vmail STATEMENT: VACUUM VERBOSE ANALYZE update_queues; > Mar 6 01:16:44 ardbc01 postgres[66365]: [14-1] mavmail@10.93.156.45:ma= vmail INFO: index "uq_qid" now contains 0 row versions in 7 pages > Mar 6 01:16:44 ardbc01 postgres[66365]: [14-2] mavmail@10.93.156.45:ma= vmail DETAIL: 0 index row versions were removed. > Mar 6 01:16:44 ardbc01 postgres[66365]: [14-3] #0114 index pages have = been deleted, 4 are currently reusable. > Mar 6 01:16:44 ardbc01 postgres[66365]: [14-4] #011CPU 0.00s/0.00u sec= elapsed 0.00 sec. > Mar 6 01:16:44 ardbc01 postgres[66365]: [14-5] mavmail@10.93.156.45:ma= vmail STATEMENT: VACUUM VERBOSE ANALYZE update_queues; > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-1] mavmail@10.93.156.45:ma= vmail INFO: "update_queues": found 0 removable, 0 nonremovable row versi= ons in 0 out of 0 pages > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-2] mavmail@10.93.156.45:ma= vmail DETAIL: 0 dead row versions cannot be removed yet. > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-3] #011There were 0 unused= item pointers. > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-4] #0110 pages are entirel= y empty. > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-5] #011CPU 0.00s/0.00u sec= elapsed 0.00 sec. > Mar 6 01:16:44 ardbc01 postgres[66365]: [15-6] mavmail@10.93.156.45:ma= vmail STATEMENT: VACUUM VERBOSE ANALYZE update_queues; > > I did check older posts on pgadmin - one insight involved the possible = inability of autovacuum to grab the latest stats as the stats collector m= ight have gotten stuck in a loop > and could not update the stats file. That was from an older PSQL versi= on and we don't employ autovacuum in these databases. > > Any insights appreciated: > postgres version: 9.2.5 > > platform: > Linux ardbc01 2.6.32-358.18.1.el6.x86_64 #1 SMP Wed Aug 28 17:19:38 U= TC 2013 x86_64 x86_64 x86_64 GNU/Linux > > Thank you, > > > *Mark Steben* > Database Administrator > @utoRevenue | Autobase =20 > CRM division of Dominion Dealer Solutions=20 > 95D Ashley Ave. > West Springfield, MA 01089 > t: 413.327-3045 > f: 413.383-9567 > > www.fb.com/DominionDealerSolutions > www.twitter.com/DominionDealer > www.drivedominion.com > > > > > --------------090608030903040800090304 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit Not to sound stupid, but two possible issues:

1) this is a really big table and
2) you have no index on the field "datname"

Possible?
Jay

On 3/9/2015 3:50 PM, Mark Steben wrote:
Good afternoon,

We have been sporadically receiving a warning:  pgstat wait timeout
in our production environment.  This has been always immediately followed by
a successful execution of the query.

EX:
 
Mar  6 00:31:29 ardbc01 postgres[42903]: [3-1] mavmail@10.93.156.42:prime_production:0WARNING:  pgstat wait timeout
Mar  6 00:31:29 ardbc01 postgres[42903]: [3-2] mavmail@10.93.156.42:prime_production:0STATEMENT:  SELECT * FROM pg_stat_database WHERE datname='prime_production';
Mar  6 00:31:29 ardbc01 postgres[42903]: [4-1] mavmail@10.93.156.42:prime_production:0LOG:  duration: 10137.143 ms  statement: SELECT * FROM pg_stat_database WHERE datname='prime_production';

and

mavmail@10.93.156.42:prime_production:0WARNING:  pgstat wait timeout
Mar  6 00:31:46 ardbc01 postgres[42903]: [6-2] mavmail@10.93.156.42:prime_production:0STATEMENT:  SELECT SUM(idx_blks_hit) AS hits, SUM(idx_blks_read) AS reads FROM pg_statio_user_indexes
Mar  6 00:31:46 ardbc01 postgres[42903]: [7-1] mavmail@10.93.156.42:prime_production:0LOG:  duration: 10144.601 ms  statement: SELECT SUM(idx_blks_hit) AS hits, SUM(idx_blks_read) AS reads FROM pg_statio_user_indexes

This is not confined to queries of pg stat infrastructure tables. In another database we can receive the same warning on a vacuum:

mavmail@10.93.156.45:mavmail WARNING:  pgstat wait timeout
Mar  6 01:16:44 ardbc01 postgres[66365]: [12-2] mavmail@10.93.156.45:mavmail STATEMENT:  VACUUM VERBOSE ANALYZE update_queues;
Mar  6 01:16:44 ardbc01 postgres[66365]: [13-1] mavmail@10.93.156.45:mavmail INFO:  vacuuming "public.update_queues"
Mar  6 01:16:44 ardbc01 postgres[66365]: [13-2] mavmail@10.93.156.45:mavmail STATEMENT:  VACUUM VERBOSE ANALYZE update_queues;
Mar  6 01:16:44 ardbc01 postgres[66365]: [14-1] mavmail@10.93.156.45:mavmail INFO:  index "uq_qid" now contains 0 row versions in 7 pages
Mar  6 01:16:44 ardbc01 postgres[66365]: [14-2] mavmail@10.93.156.45:mavmail DETAIL:  0 index row versions were removed.
Mar  6 01:16:44 ardbc01 postgres[66365]: [14-3] #0114 index pages have been deleted, 4 are currently reusable.
Mar  6 01:16:44 ardbc01 postgres[66365]: [14-4] #011CPU 0.00s/0.00u sec elapsed 0.00 sec.
Mar  6 01:16:44 ardbc01 postgres[66365]: [14-5] mavmail@10.93.156.45:mavmail STATEMENT:  VACUUM VERBOSE ANALYZE update_queues;
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-1] mavmail@10.93.156.45:mavmail INFO:  "update_queues": found 0 removable, 0 nonremovable row versions in 0 out of 0 pages
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-2] mavmail@10.93.156.45:mavmail DETAIL:  0 dead row versions cannot be removed yet.
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-3] #011There were 0 unused item pointers.
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-4] #0110 pages are entirely empty.
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-5] #011CPU 0.00s/0.00u sec elapsed 0.00 sec.
Mar  6 01:16:44 ardbc01 postgres[66365]: [15-6] mavmail@10.93.156.45:mavmail STATEMENT:  VACUUM VERBOSE ANALYZE update_queues;

I did check older posts on pgadmin - one insight involved the possible inability of autovacuum to grab the latest stats as the stats collector might have gotten stuck in a loop and could not update the stats file.  That was from an older PSQL version and we don't employ autovacuum in these databases.

Any insights appreciated:
  postgres version: 9.2.5

  platform:
  Linux ardbc01 2.6.32-358.18.1.el6.x86_64 #1 SMP Wed Aug 28 17:19:38 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

Thank you,


Mark Steben
 Database Administrator
@utoRevenue | Autobase 
  CRM division of Dominion Dealer Solutions 
95D Ashley Ave.
West Springfield, MA 01089
t: 413.327-3045
f: 413.383-9567

www.fb.com/DominionDealerSolutions
www.twitter.com/DominionDealer
 www.drivedominion.com






--------------090608030903040800090304--