Summary Sort workers Stats in EXPLAIN ANALYZE

Lists: pgsql-hackers
From: Jian Guo <gjian(at)vmware(dot)com>
To: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-21 03:36:17
Message-ID: BL0PR05MB5188210988EA15126C255B6DC4169@BL0PR05MB5188.namprd05.prod.outlook.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers


In current EXPLAIN ANALYZE implementation, the Sort Node stats from each workers are not summarized: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2762

When the worker number is large, it will print out huge amount of node details in the plan. I have created this patch to summarize the tuplesort stats by AverageSpaceUsed / PeakSpaceUsed, make it behave just like in `show_incremental_sort_group_info()`: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890

Attachment Content-Type Size
0001-Summary-Sort-workers-Stats.patch text/x-patch 2.7 KB

From: Jian Guo <gjian(at)vmware(dot)com>
To: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-21 07:50:38
Message-ID: SN6PR05MB5199C4190643F55C00E3CC0EC4169@SN6PR05MB5199.namprd05.prod.outlook.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

There is some problem with the last patch, I have removed the `ExplainOpenWorker` call to fix.

And also, I have added a test case in explain.sql​ according to the code change.
________________________________
From: Jian Guo <gjian(at)vmware(dot)com>
Sent: Monday, March 21, 2022 11:36
To: pgsql-hackers(at)lists(dot)postgresql(dot)org <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Summary Sort workers Stats in EXPLAIN ANALYZE

In current EXPLAIN ANALYZE implementation, the Sort Node stats from each workers are not summarized: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2762<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fp.rizon.top%3A443%2Fhttps%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2762&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=RXY0uDuK7cFraHJqwU%2FQv%2BXhq3n%2F2cO6nv%2BoxHTbmCM%3D&reserved=0>

When the worker number is large, it will print out huge amount of node details in the plan. I have created this patch to summarize the tuplesort stats by AverageSpaceUsed / PeakSpaceUsed, make it behave just like in `show_incremental_sort_group_info()`: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fp.rizon.top%3A443%2Fhttps%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2890&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=NotrZFufFycTmlVy3SKioUSWGzLalSu9SWCOccMXGCI%3D&reserved=0>

Attachment Content-Type Size
0001-Summary-Sort-workers-Stats.patch text/x-patch 37.3 KB

From: Jian Guo <gjian(at)vmware(dot)com>
To: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-24 07:50:11
Message-ID: SN6PR05MB519978F0435079207762C54EC4199@SN6PR05MB5199.namprd05.prod.outlook.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

For a simple demo, with this explain statement:

-- Test sort stats summary
set force_parallel_mode=on;
select explain_filter('explain (analyze, summary off, timing off, costs off, format json) select * from tenk1 order by unique1');

Before this patch, we got plan like this:

"Node Type": "Sort", +
"Parent Relationship": "Outer", +
"Parallel Aware": false, +
"Async Capable": false, +
"Actual Rows": 10000, +
"Actual Loops": 1, +
"Sort Key": ["unique1"], +
"Workers": [ +
{ +
"Worker Number": 0, +
"Sort Method": "external merge",+
"Sort Space Used": 2496, +
"Sort Space Type": "Disk" +
} +
], +

After this patch, the effected plan is this:

"Node Type": "Sort", +
"Parent Relationship": "Outer", +
"Parallel Aware": false, +
"Async Capable": false, +
"Actual Rows": N, +
"Actual Loops": N, +
"Sort Key": ["unique1"], +
"Workers planned": N, +
"Sort Method": "external merge", +
"Average Sort Space Used": N, +
"Peak Sort Space Used": N, +
"Sort Space Type": "Disk", +
________________________________
From: Jian Guo <gjian(at)vmware(dot)com>
Sent: Monday, March 21, 2022 15:50
To: pgsql-hackers(at)lists(dot)postgresql(dot)org <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE

There is some problem with the last patch, I have removed the `ExplainOpenWorker` call to fix.

And also, I have added a test case in explain.sql​ according to the code change.
________________________________
From: Jian Guo <gjian(at)vmware(dot)com>
Sent: Monday, March 21, 2022 11:36
To: pgsql-hackers(at)lists(dot)postgresql(dot)org <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Summary Sort workers Stats in EXPLAIN ANALYZE

In current EXPLAIN ANALYZE implementation, the Sort Node stats from each workers are not summarized: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2762<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fp.rizon.top%3A443%2Fhttps%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2762&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=RXY0uDuK7cFraHJqwU%2FQv%2BXhq3n%2F2cO6nv%2BoxHTbmCM%3D&reserved=0>

When the worker number is large, it will print out huge amount of node details in the plan. I have created this patch to summarize the tuplesort stats by AverageSpaceUsed / PeakSpaceUsed, make it behave just like in `show_incremental_sort_group_info()`: https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890<https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fp.rizon.top%3A443%2Fhttps%2Fgithub.com%2Fpostgres%2Fpostgres%2Fblob%2Fd4ba8b51c76300f06cc23f4d8a41d9f7210c4866%2Fsrc%2Fbackend%2Fcommands%2Fexplain.c%23L2890&data=04%7C01%7Cgjian%40vmware.com%7C0f2c3df25e8a46bdd84f08da0aebff59%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637834305971955895%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000&sdata=NotrZFufFycTmlVy3SKioUSWGzLalSu9SWCOccMXGCI%3D&reserved=0>


From: Julien Rouhaud <rjuju123(at)gmail(dot)com>
To: Jian Guo <gjian(at)vmware(dot)com>
Cc: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>, Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-25 09:04:53
Message-ID: 20220325090453.3bwhbs4nphrk4cmp@jrouhaud
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

Hi,

On Thu, Mar 24, 2022 at 07:50:11AM +0000, Jian Guo wrote:
> For a simple demo, with this explain statement:
>
> -- Test sort stats summary
> set force_parallel_mode=on;
> select explain_filter('explain (analyze, summary off, timing off, costs off, format json) select * from tenk1 order by unique1');
>
> Before this patch, we got plan like this:
>
>
> "Node Type": "Sort", +
> "Parent Relationship": "Outer", +
> "Parallel Aware": false, +
> "Async Capable": false, +
> "Actual Rows": 10000, +
> "Actual Loops": 1, +
> "Sort Key": ["unique1"], +
> "Workers": [ +
> { +
> "Worker Number": 0, +
> "Sort Method": "external merge",+
> "Sort Space Used": 2496, +
> "Sort Space Type": "Disk" +
> } +
> ], +

> After this patch, the effected plan is this:
>
> "Node Type": "Sort", +
> "Parent Relationship": "Outer", +
> "Parallel Aware": false, +
> "Async Capable": false, +
> "Actual Rows": N, +
> "Actual Loops": N, +
> "Sort Key": ["unique1"], +
> "Workers planned": N, +
> "Sort Method": "external merge", +
> "Average Sort Space Used": N, +
> "Peak Sort Space Used": N, +
> "Sort Space Type": "Disk", +

I think the idea is interesting, however there are a few problems in the patch.

First, I think that it should only be done in the VERBOSE OFF mode. If you ask
for a VERBOSE output you don't need both the details and the summarized
version.

Other minor problems:

- why (only) emitting the number of workers planned and not the number of
workers launched?
- the textual format is missing details about what the numbers are, which is
particularly obvious since avgSpaceUsed and peakSpaceUsed don't have any unit
or even space between them:

+ "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT "kB\n",
+ sortMethod, spaceType, avgSpaceUsed, peakSpaceUsed);


From: Julien Rouhaud <rjuju123(at)gmail(dot)com>
To: Jian Guo <gjian(at)vmware(dot)com>
Cc: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>, Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-25 09:30:30
Message-ID: 20220325093030.cvays6d6mzhbv76a@jrouhaud
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

On Fri, Mar 25, 2022 at 05:04:53PM +0800, Julien Rouhaud wrote:
> I think the idea is interesting, however there are a few problems in the patch.
>
> First, I think that it should only be done in the VERBOSE OFF mode. If you ask
> for a VERBOSE output you don't need both the details and the summarized
> version.
>
> Other minor problems:
>
> - why (only) emitting the number of workers planned and not the number of
> workers launched?
> - the textual format is missing details about what the numbers are, which is
> particularly obvious since avgSpaceUsed and peakSpaceUsed don't have any unit
> or even space between them:
>
> + "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT "kB\n",
> + sortMethod, spaceType, avgSpaceUsed, peakSpaceUsed);

Also I didn't find your patch in the next commitfest [1]. Please register it
to make sure that it's not forgotten. Not that we're already at the end of the
last pg15 commitfest, so this should be material for pg16.

[1] https://commitfest.postgresql.org/38/


From: Jian Guo <gjian(at)vmware(dot)com>
To: Julien Rouhaud <rjuju123(at)gmail(dot)com>
Cc: "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>, Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-03-28 09:55:39
Message-ID: SN6PR05MB51994625107817328C89FE34C41D9@SN6PR05MB5199.namprd05.prod.outlook.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers


I have updated the patch addressing the review comments, but I didn't moved this code block into VERBOSE mode, to keep consistency with `show_incremental_sort_info`:

https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890

Please review, thanks.

________________________________
From: Julien Rouhaud <rjuju123(at)gmail(dot)com>
Sent: Friday, March 25, 2022 17:04
To: Jian Guo <gjian(at)vmware(dot)com>
Cc: pgsql-hackers(at)lists(dot)postgresql(dot)org <pgsql-hackers(at)lists(dot)postgresql(dot)org>; Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE

⚠ External Email

Hi,

On Thu, Mar 24, 2022 at 07:50:11AM +0000, Jian Guo wrote:
> For a simple demo, with this explain statement:
>
> -- Test sort stats summary
> set force_parallel_mode=on;
> select explain_filter('explain (analyze, summary off, timing off, costs off, format json) select * from tenk1 order by unique1');
>
> Before this patch, we got plan like this:
>
>
> "Node Type": "Sort", +
> "Parent Relationship": "Outer", +
> "Parallel Aware": false, +
> "Async Capable": false, +
> "Actual Rows": 10000, +
> "Actual Loops": 1, +
> "Sort Key": ["unique1"], +
> "Workers": [ +
> { +
> "Worker Number": 0, +
> "Sort Method": "external merge",+
> "Sort Space Used": 2496, +
> "Sort Space Type": "Disk" +
> } +
> ], +

> After this patch, the effected plan is this:
>
> "Node Type": "Sort", +
> "Parent Relationship": "Outer", +
> "Parallel Aware": false, +
> "Async Capable": false, +
> "Actual Rows": N, +
> "Actual Loops": N, +
> "Sort Key": ["unique1"], +
> "Workers planned": N, +
> "Sort Method": "external merge", +
> "Average Sort Space Used": N, +
> "Peak Sort Space Used": N, +
> "Sort Space Type": "Disk", +

I think the idea is interesting, however there are a few problems in the patch.

First, I think that it should only be done in the VERBOSE OFF mode. If you ask
for a VERBOSE output you don't need both the details and the summarized
version.

Other minor problems:

- why (only) emitting the number of workers planned and not the number of
workers launched?
- the textual format is missing details about what the numbers are, which is
particularly obvious since avgSpaceUsed and peakSpaceUsed don't have any unit
or even space between them:

+ "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT "kB\n",
+ sortMethod, spaceType, avgSpaceUsed, peakSpaceUsed);

________________________________

⚠ External Email: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender.

Attachment Content-Type Size
0002-Summary-Sort-workers-Stats.patch text/x-patch 37.2 KB

From: Ibrar Ahmed <ibrar(dot)ahmad(at)gmail(dot)com>
To: Jian Guo <gjian(at)vmware(dot)com>, "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Cc: Julien Rouhaud <rjuju123(at)gmail(dot)com>, Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-09-06 06:37:32
Message-ID: CALtqXTdhhiS_H9Dt0bL04sYXGRtJbDqSYNA+mBi3Xpg2xOD9OA@mail.gmail.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

On Mon, Mar 28, 2022 at 2:55 PM Jian Guo <gjian(at)vmware(dot)com> wrote:

>
> I have updated the patch addressing the review comments, but I didn't
> moved this code block into VERBOSE mode, to keep consistency with `
> show_incremental_sort_info`:
>
>
> https://github.com/postgres/postgres/blob/d4ba8b51c76300f06cc23f4d8a41d9f7210c4866/src/backend/commands/explain.c#L2890
>
> Please review, thanks.
>
> ------------------------------
> *From:* Julien Rouhaud <rjuju123(at)gmail(dot)com>
> *Sent:* Friday, March 25, 2022 17:04
> *To:* Jian Guo <gjian(at)vmware(dot)com>
> *Cc:* pgsql-hackers(at)lists(dot)postgresql(dot)org <
> pgsql-hackers(at)lists(dot)postgresql(dot)org>; Zhenghua Lyu <zlyu(at)vmware(dot)com>
> *Subject:* Re: Summary Sort workers Stats in EXPLAIN ANALYZE
>
> ⚠ External Email
>
> Hi,
>
> On Thu, Mar 24, 2022 at 07:50:11AM +0000, Jian Guo wrote:
> > For a simple demo, with this explain statement:
> >
> > -- Test sort stats summary
> > set force_parallel_mode=on;
> > select explain_filter('explain (analyze, summary off, timing off, costs
> off, format json) select * from tenk1 order by unique1');
> >
> > Before this patch, we got plan like this:
> >
> >
> > "Node Type": "Sort", +
> > "Parent Relationship": "Outer", +
> > "Parallel Aware": false, +
> > "Async Capable": false, +
> > "Actual Rows": 10000, +
> > "Actual Loops": 1, +
> > "Sort Key": ["unique1"], +
> > "Workers": [ +
> > { +
> > "Worker Number": 0, +
> > "Sort Method": "external merge",+
> > "Sort Space Used": 2496, +
> > "Sort Space Type": "Disk" +
> > } +
> > ], +
>
> > After this patch, the effected plan is this:
> >
> > "Node Type": "Sort", +
> > "Parent Relationship": "Outer", +
> > "Parallel Aware": false, +
> > "Async Capable": false, +
> > "Actual Rows": N, +
> > "Actual Loops": N, +
> > "Sort Key": ["unique1"], +
> > "Workers planned": N, +
> > "Sort Method": "external merge", +
> > "Average Sort Space Used": N, +
> > "Peak Sort Space Used": N, +
> > "Sort Space Type": "Disk", +
>
> I think the idea is interesting, however there are a few problems in the
> patch.
>
> First, I think that it should only be done in the VERBOSE OFF mode. If
> you ask
> for a VERBOSE output you don't need both the details and the summarized
> version.
>
> Other minor problems:
>
> - why (only) emitting the number of workers planned and not the number of
> workers launched?
> - the textual format is missing details about what the numbers are, which
> is
> particularly obvious since avgSpaceUsed and peakSpaceUsed don't have any
> unit
> or even space between them:
>
> + "Sort Method: %s %s: " INT64_FORMAT INT64_FORMAT
> "kB\n",
> + sortMethod, spaceType, avgSpaceUsed,
> peakSpaceUsed);
>
>
> ________________________________
>
> ⚠ External Email: This email originated from outside of the organization.
> Do not click links or open attachments unless you recognize the sender.
>

The patch failed different regression tests on all platforms. Please
correct that and send an updated patch.

[06:40:02.370] Test Summary Report
[06:40:02.370] -------------------
[06:40:02.370] t/002_pg_upgrade.pl (Wstat: 256 Tests: 13 Failed: 1)
[06:40:02.370] Failed test: 4
[06:40:02.370] Non-zero exit status: 1
[06:40:02.370] Files=2, Tests=21, 45 wallclock secs ( 0.02 usr 0.00 sys +
3.52 cusr 2.06 csys = 5.60 CPU)
--
Ibrar Ahmed


From: Michael Paquier <michael(at)paquier(dot)xyz>
To: Ibrar Ahmed <ibrar(dot)ahmad(at)gmail(dot)com>
Cc: Jian Guo <gjian(at)vmware(dot)com>, "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>, Julien Rouhaud <rjuju123(at)gmail(dot)com>, Zhenghua Lyu <zlyu(at)vmware(dot)com>
Subject: Re: Summary Sort workers Stats in EXPLAIN ANALYZE
Date: 2022-10-12 08:42:15
Message-ID: [email protected]
Views: Whole Thread | Raw Message | Download mbox | Resend email
Lists: pgsql-hackers

On Tue, Sep 06, 2022 at 11:37:32AM +0500, Ibrar Ahmed wrote:
> The patch failed different regression tests on all platforms. Please
> correct that and send an updated patch.
>
> [06:40:02.370] Test Summary Report
> [06:40:02.370] -------------------
> [06:40:02.370] t/002_pg_upgrade.pl (Wstat: 256 Tests: 13 Failed: 1)
> [06:40:02.370] Failed test: 4
> [06:40:02.370] Non-zero exit status: 1
> [06:40:02.370] Files=2, Tests=21, 45 wallclock secs ( 0.02 usr 0.00 sys +
> 3.52 cusr 2.06 csys = 5.60 CPU)

This has been marked as RwF based on the lack of an update.
--
Michael