Обсуждение: CLUSTER VERBOSE (9.1.3)
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 Is there any way to get more info out of CLUSTER VERBOSE so it says what index it's working on AFTER the table re-write? INFO: clustering "public.values" using sequential scan and sort INFO: "values": found 0 removable, 260953511 nonremovable row versions in 4224437 pages DETAIL: 0 dead row versions cannot be removed yet. CPU 168.02s/4324.68u sec elapsed 8379.12 sec. And at this point it's doing something(tm), I assume re-doing the indexes. It would be nice(tm) to get more info. Ideas? - -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 512-248-2683 E-Mail: ler@lerctr.org US Mail: 430 Valona Loop, Round Rock, TX 78681-3893 -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.17 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iQEcBAEBAgAGBQJPVTLJAAoJENC8dtAvA1zmolAIAIgfqXTe5cWZ2ZGVXXVgzv3A pBhi1bVOEB8Xjcie82gMTyqBZKuTtIqNFHXWaB4xVxG6U93YGlru7DnUa8ArzbvW 31b0GHIeXpemUFz0OnuKv6h0Bt+H755YNuDXykN7a7VEdzwIrv/iSSGlBsbEywhG SdC1VvHrmUaRCfCV/XBF4tynC3rocRIyf29SJNPZJl9cJtkK2BDigUeHANN3mydQ 1H1WZ8CMfnTvi8vROGFuk5HCZDv0e9K9dYthfMEqIgKzBRu5jLagijADyEhVCJfO /JYP+t1eGPP1zYqf+R/OfMGTM0RYcP/XVRK8qS+8FPBTUPTphStjmOBPuHRYWDU= =GWPN -----END PGP SIGNATURE-----
On Mon, Mar 5, 2012 at 4:40 PM, Larry Rosenman <ler@lerctr.org> wrote: > -----BEGIN PGP SIGNED MESSAGE----- > Hash: SHA1 > > Is there any way to get more info out of CLUSTER VERBOSE so it says > what index it's working on AFTER the table re-write? > > INFO: clustering "public.values" using sequential scan and sort > INFO: "values": found 0 removable, 260953511 nonremovable row > versions in 4224437 pages > DETAIL: 0 dead row versions cannot be removed yet. > CPU 168.02s/4324.68u sec elapsed 8379.12 sec. > > > And at this point it's doing something(tm), I assume re-doing the indexes. > > It would be nice(tm) to get more info. > > Ideas? Try setting client_min_messages=DEBUG1. At least on current sources that gives some additional, relevant output; I think that's probably there in 9.1.x as well. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 3/6/2012 8:32 AM, Robert Haas wrote: > On Mon, Mar 5, 2012 at 4:40 PM, Larry Rosenman <ler@lerctr.org> > wrote: >> -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 >> >> Is there any way to get more info out of CLUSTER VERBOSE so it >> says what index it's working on AFTER the table re-write? >> >> INFO: clustering "public.values" using sequential scan and sort >> INFO: "values": found 0 removable, 260953511 nonremovable row >> versions in 4224437 pages DETAIL: 0 dead row versions cannot be >> removed yet. CPU 168.02s/4324.68u sec elapsed 8379.12 sec. >> >> >> And at this point it's doing something(tm), I assume re-doing the >> indexes. >> >> It would be nice(tm) to get more info. >> >> Ideas? > > Try setting client_min_messages=DEBUG1. At least on current > sources that gives some additional, relevant output; I think that's > probably there in 9.1.x as well. > Thanks. That helps some, but I'd like to see: 1) these moved up to INFO when CLUSTER VERBOSE 2) time/statistics on each index build INFO: clustering "public.values" using sequential scan and sort INFO: "values": found 0 removable, 260953511 nonremovable row versions in 4224437 pages DETAIL: 0 dead row versions cannot be removed yet. CPU 167.57s/4325.52u sec elapsed 7687.28 sec. DEBUG: building index "values_idx1" on table "values" DEBUG: building index "values_idx2" on table "values" DEBUG: building index "values_idx3" on table "values" DEBUG: building index "values_idx4" on table "values" DEBUG: building index "values_idx5" on table "values" DEBUG: building index "values_idx6" on table "values" DEBUG: building index "values_idx7" on table "values" DEBUG: building index "values_idx_cluster" on table "values" CLUSTER Time: 28997806.474 ms Comments? - -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 512-248-2683 E-Mail: ler@lerctr.org US Mail: 430 Valona Loop, Round Rock, TX 78681-3893 -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.17 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iQEcBAEBAgAGBQJPV3GyAAoJENC8dtAvA1zmAzkIALJL/Ir7Ks3gYVy4bVB7Oamc Etpg6/hmM3+g0Ry9Lv3yUbaeHLxwuAaW+Gv5nDuepZFbMfAxYjsUG+fVUu8n3Xo3 V42/4TFxI7QQUtnwqkkMo0Y1vBNsmIRFuxx3b2R+ePKAZaQFLoElU7dL1JOA1u3c OQ0dUDtiUNTSa+ZrNYNbLhqOUUIooGrF8hWLKfmLOrbrRpAObrCeyaHW2qxRrIq/ wbvHG7YG1byRiDzZr4DNKrS4/88HXjgo2m8xmxyNf+1fKsa69fkIA+rbsqyEx4ui RAih9fQVQcjcK15XTyDchT21YRdwDZnjVt/Yh0IMvDE19sIQFfrs1QTGPnUULpI= =5bZG -----END PGP SIGNATURE-----
On Wed, Mar 7, 2012 at 9:33 AM, Larry Rosenman <ler@lerctr.org> wrote: >>> Is there any way to get more info out of CLUSTER VERBOSE so it >>> says what index it's working on AFTER the table re-write? >>> >>> INFO: clustering "public.values" using sequential scan and sort >>> INFO: "values": found 0 removable, 260953511 nonremovable row >>> versions in 4224437 pages DETAIL: 0 dead row versions cannot be >>> removed yet. CPU 168.02s/4324.68u sec elapsed 8379.12 sec. >>> >>> >>> And at this point it's doing something(tm), I assume re-doing the >>> indexes. >>> >>> It would be nice(tm) to get more info. >>> >>> Ideas? >> >> Try setting client_min_messages=DEBUG1. At least on current >> sources that gives some additional, relevant output; I think that's >> probably there in 9.1.x as well. >> > Thanks. That helps some, but I'd like to see: > 1) these moved up to INFO when CLUSTER VERBOSE > 2) time/statistics on each index build > > INFO: clustering "public.values" using sequential scan and sort > INFO: "values": found 0 removable, 260953511 nonremovable row > versions in 4224437 pages > DETAIL: 0 dead row versions cannot be removed yet. > CPU 167.57s/4325.52u sec elapsed 7687.28 sec. > DEBUG: building index "values_idx1" on table "values" > DEBUG: building index "values_idx2" on table "values" > DEBUG: building index "values_idx3" on table "values" > DEBUG: building index "values_idx4" on table "values" > DEBUG: building index "values_idx5" on table "values" > DEBUG: building index "values_idx6" on table "values" > DEBUG: building index "values_idx7" on table "values" > DEBUG: building index "values_idx_cluster" on table "values" > CLUSTER > Time: 28997806.474 ms > > Comments? Seems like a good enhancement to me, if someone can figure out how to do it cleanly. Unfortunately those debug messages may not be in a place where it's real easy for them to know whether they're being called from CLUSTER VERBOSE or not, so it might take a little thought to produce a clean patch for this. -- Robert Haas EnterpriseDB: http://www.enterprisedb.com The Enterprise PostgreSQL Company
Excerpts from Robert Haas's message of mié mar 07 11:57:41 -0300 2012: > Seems like a good enhancement to me, if someone can figure out how to > do it cleanly. Unfortunately those debug messages may not be in a > place where it's real easy for them to know whether they're being > called from CLUSTER VERBOSE or not, so it might take a little thought > to produce a clean patch for this. Another thing that occured to me in this general area was whether it'd be useful to do something with ps_status and pg_stat_activity. Also, this isn't limited to CLUSTER; anything that rewrites the table and indexes would benefit. Meaning ALTER TABLE that does a full rewrite, and also VACUUM FULL. -- Álvaro Herrera <alvherre@commandprompt.com> The PostgreSQL Company - Command Prompt, Inc. PostgreSQL Replication, Consulting, Custom Development, 24x7 support
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 3/7/2012 12:31 PM, Alvaro Herrera wrote: > > Excerpts from Robert Haas's message of mié mar 07 11:57:41 -0300 > 2012: > >> Seems like a good enhancement to me, if someone can figure out >> how to do it cleanly. Unfortunately those debug messages may not >> be in a place where it's real easy for them to know whether >> they're being called from CLUSTER VERBOSE or not, so it might >> take a little thought to produce a clean patch for this. > > Another thing that occured to me in this general area was whether > it'd be useful to do something with ps_status and > pg_stat_activity. > > Also, this isn't limited to CLUSTER; anything that rewrites the > table and indexes would benefit. Meaning ALTER TABLE that does a > full rewrite, and also VACUUM FULL. > +1. I think we should update ps_status as well as pg_stat_activity as all of these table rewrite processes are running. Do I need to cogitate on the code, or is one of the hackers that knows it better interested? Thanks! - -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 512-248-2683 E-Mail: ler@lerctr.org US Mail: 430 Valona Loop, Round Rock, TX 78681-3893 -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.17 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iQEcBAEBAgAGBQJPV64WAAoJENC8dtAvA1zmItsH/ib0uAh3Jqy6WKXrxBrJoy5k LBj/xfAs8Z3Xl0TQjoulgAgBV1NWo5DyKvvtmcxpEw1KkJZrpkWONB3I+Y3nQKiy rfD3uJ6tWvoD9Ay+InPy0W8qReTSKSSI09au60OzU8Ez3UX5JEGhiibn1B6AvXKy 5JWGRJF64fKEnDOresVHqGGhlLM3lelsS7nMX0rs8kZ20BG3tLPjqZslm/qZ3w9M OJJpJKOlZCoNs+YZTtNxGeRhKXWSfsao6tYc/8To7pbJ6m9MKyqcou7g8yJXZrJr +BFwPyRG+/p6Li0tWmsuD8FtuPFFp37HxeduKzJNN9sqA3TSeadN8kZweb8zak8= =jrEi -----END PGP SIGNATURE-----
Larry Rosenman <ler@lerctr.org> writes:
> On 3/7/2012 12:31 PM, Alvaro Herrera wrote:
>> Also, this isn't limited to CLUSTER; anything that rewrites the
>> table and indexes would benefit. Meaning ALTER TABLE that does a
>> full rewrite, and also VACUUM FULL.
> +1. I think we should update ps_status as well as pg_stat_activity as
> all of these table rewrite processes are running.
-1. Updating ps_status is expensive, seriously so on some platforms.
We could likely get away with tracking progress in pg_stat_activity
though.
However, this just reminds me that tracking intrastatement progress in
pg_stat_activity has been discussed before and not much has happened.
Let's please not have a quick kluge that just addresses CLUSTER and not
any of the other aspects of that problem.
regards, tom lane
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1 On 3/7/2012 2:42 PM, Tom Lane wrote: > Larry Rosenman <ler@lerctr.org> writes: >> On 3/7/2012 12:31 PM, Alvaro Herrera wrote: >>> Also, this isn't limited to CLUSTER; anything that rewrites >>> the table and indexes would benefit. Meaning ALTER TABLE that >>> does a full rewrite, and also VACUUM FULL. > >> +1. I think we should update ps_status as well as >> pg_stat_activity as all of these table rewrite processes are >> running. > > -1. Updating ps_status is expensive, seriously so on some > platforms. We could likely get away with tracking progress in > pg_stat_activity though. > > However, this just reminds me that tracking intrastatement progress > in pg_stat_activity has been discussed before and not much has > happened. Let's please not have a quick kluge that just addresses > CLUSTER and not any of the other aspects of that problem. > > regards, tom lane > OOppss. I forgot that it's expensive on ps_status (I think my favorite platform, FreeBSD, is one of those :(). I do think that pg_stat_activity should be updated, as well as pushing more of the DEBUG1 progress messages up to INFO, and adding some sort of timing / statistical info on the create index commands that are run. Is any of the -hackers community interested, or should I try(!) to look at the code? - -- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 512-248-2683 E-Mail: ler@lerctr.org US Mail: 430 Valona Loop, Round Rock, TX 78681-3893 -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.17 (MingW32) Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/ iQEcBAEBAgAGBQJPV8rRAAoJENC8dtAvA1zmt90IAL7M15RBl6k03Tq18ehUMdos SKSAT/dSPEaQJx55GIPNy+uE6miiNS8Vo493SJ007hsyob/fuxdhXMfWalrc/qdE BFsIBNiGJEsy0kyQxhXmXneQurgt1jbntGmCc/rSybd7aDq72fE81G6NaQGXqIOq FMl3MqQpQuOjL8cCfGgwpsV9paipmlcQTzc52aAcj1Yj15twFySx/P3N18oNX9NP 6JUEgEl6FLP0UQ31roxzbulLR0imoACAThaOOp1swxPREahjkltoU08wk/MeR6xv hR76is80/16I1hj6DLXwAl6C/Dmmt3ufrKTHKguXJU6RAJI11+05MbSiBIO5wCI= =rWW2 -----END PGP SIGNATURE-----