public inbox for [email protected]  
help / color / mirror / Atom feed
From: Igor Neyman <[email protected]>
To: Igor Neyman <[email protected]>
To: Charles Nadeau <[email protected]>
To: Jeff Janes <[email protected]>
Cc: [email protected] <[email protected]>
Subject: Re: Very poor read performance, query independent
Date: Wed, 12 Jul 2017 16:39:08 +0000
Message-ID: <DM5PR07MB2810C1580B17D1BF15B15AE5DAAF0@DM5PR07MB2810.namprd07.prod.outlook.com> (raw)
In-Reply-To: <DM5PR07MB28101CDEC281CFA491B455E5DAAF0@DM5PR07MB2810.namprd07.prod.outlook.com>
References: <CADFyZw7aGoD0AaStxdyHByR5Qta=M5wx0v=iptKLhPUp+EOKvA@mail.gmail.com>
	<CAMkU=1z92pimpoDV1oTpd4AvSHS0CrLzQDFSxw1Z5cpmmjEOkw@mail.gmail.com>
	<CADFyZw7Am=mv-6RXOr_C2oxEhPyKjnbvFgaEPq+-aKw+j9oDrw@mail.gmail.com>
	<CAMkU=1zD=SNFF=U-HtRHcu2dAdqyorD6o_UCQoYHuoh-gcs_uA@mail.gmail.com>
	<CADFyZw4RTBtWUeo-6Q_GcsqawkF+gSe4JGEpASUE6msiu=01xA@mail.gmail.com>
	<DM5PR07MB28101CDEC281CFA491B455E5DAAF0@DM5PR07MB2810.namprd07.prod.outlook.com>
List-Unsubscribe:  <mailto:[email protected]?body=unsub%20pgsql-performance>



From: [email protected]<mailto:[email protected]> [mailto:[email protected]] On Behalf Of Charles Nadeau
Sent: Wednesday, July 12, 2017 6:05 AM
To: Jeff Janes <[email protected]<mailto:[email protected]>>
Cc: [email protected]<mailto:[email protected]>
Subject: Re: [PERFORM] Very poor read performance, query independent


flows=# explain (analyze, buffers) SELECT DISTINCT
flows-#    srcaddr,
flows-#    dstaddr,
flows-#    dstport,
flows-#    COUNT(*) AS conversation,
flows-#    SUM(doctets) / 1024 / 1024 AS mbytes
flows-# FROM
flows-#    flowscompact,
flows-#    mynetworks
flows-# WHERE
flows-#    mynetworks.ipaddr >>= flowscompact.srcaddr
flows-#    AND dstaddr IN
flows-#    (
flows(#       SELECT
flows(#          dstaddr
flows(#       FROM
flows(#          dstexterne
flows(#    )
flows-# GROUP BY
flows-#    srcaddr,
flows-#    dstaddr,
flows-#    dstport
flows-# ORDER BY
flows-#    mbytes DESC LIMIT 50;
LOG:  temporary file: path "pg_tblspc/36238/PG_9.6_201608131/pgsql_tmp/pgsql_tmp14573.6", size 1073741824
LOG:  temporary file: path "pg_tblspc/36238/PG_9.6_201608131/pgsql_tmp/pgsql_tmp14573.7", size 1073741824
LOG:  temporary file: path "pg_tblspc/36238/PG_9.6_201608131/pgsql_tmp/pgsql_tmp14573.8", size 639696896
LOG:  duration: 2765020.327 ms  statement: explain (analyze, buffers) SELECT DISTINCT
   srcaddr,
   dstaddr,
   dstport,
   COUNT(*) AS conversation,
   SUM(doctets) / 1024 / 1024 AS mbytes
FROM
   flowscompact,
   mynetworks
WHERE
   mynetworks.ipaddr >>= flowscompact.srcaddr
   AND dstaddr IN
   (
      SELECT
         dstaddr
      FROM
         dstexterne
   )
GROUP BY
   srcaddr,
   dstaddr,
   dstport
ORDER BY
   mbytes DESC LIMIT 50;
                                                                                                              QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=37762321.83..37762321.98 rows=50 width=52) (actual time=2764548.863..2764548.891 rows=50 loops=1)
   Buffers: shared hit=1116590560 read=15851133, temp read=340244 written=340244
   I/O Timings: read=5323746.860
   ->  Unique  (cost=37762321.83..37769053.57 rows=2243913 width=52) (actual time=2764548.861..2764548.882 rows=50 loops=1)
         Buffers: shared hit=1116590560 read=15851133, temp read=340244 written=340244
         I/O Timings: read=5323746.860
         ->  Sort  (cost=37762321.83..37763443.79 rows=2243913 width=52) (actual time=2764548.859..2764548.872 rows=50 loops=1)
               Sort Key: (((sum(flows.doctets) / '1024'::numeric) / '1024'::numeric)) DESC, flows.srcaddr, flows.dstaddr, flows.dstport, (count(*))
               Sort Method: quicksort  Memory: 563150kB
               Buffers: shared hit=1116590560 read=15851133, temp read=340244 written=340244
               I/O Timings: read=5323746.860
               ->  GroupAggregate  (cost=37698151.34..37714980.68 rows=2243913 width=52) (actual time=2696721.610..2752109.551 rows=4691734 loops=1)
                     Group Key: flows.srcaddr, flows.dstaddr, flows.dstport
                     Buffers: shared hit=1116590560 read=15851133, temp read=340244 written=340244
                     I/O Timings: read=5323746.860
                     ->  Sort  (cost=37698151.34..37699273.29 rows=2243913 width=20) (actual time=2696711.428..2732781.705 rows=81896988 loops=1)
                           Sort Key: flows.srcaddr, flows.dstaddr, flows.dstport
                           Sort Method: external merge  Disk: 2721856kB
                           Buffers: shared hit=1116590560 read=15851133, temp read=340244 written=340244
                           I/O Timings: read=5323746.860
                           ->  Gather  (cost=19463936.00..37650810.19 rows=2243913 width=20) (actual time=1777219.713..2590530.887 rows=81896988 loops=1)
                                 Workers Planned: 9
                                 Workers Launched: 9
                                 Buffers: shared hit=1116590559 read=15851133
                                 I/O Timings: read=5323746.860
                                 ->  Hash Semi Join  (cost=19462936.00..37622883.23 rows=249324 width=20) (actual time=1847579.360..2602039.780 rows=8189699 loops=10)
                                       Hash Cond: (flows.dstaddr = flows_1.dstaddr)
                                       Buffers: shared hit=1116588309 read=15851133
                                       I/O Timings: read=5323746.860
                                       ->  Nested Loop  (cost=0.03..18159012.30 rows=249324 width=20) (actual time=1.562..736556.583 rows=45499045 loops=10)
                                             Buffers: shared hit=996551813 read=15851133
                                             I/O Timings: read=5323746.860
                                             ->  Parallel Seq Scan on flows  (cost=0.00..16039759.79 rows=62330930 width=20) (actual time=1.506..547485.066 rows=54155970 loops=10)
                                                   Buffers: shared hit=1634 read=15851133
                                                   I/O Timings: read=5323746.860
                                             ->  Index Only Scan using mynetworks_ipaddr_idx on mynetworks  (cost=0.03..0.03 rows=1 width=8) (actual time=0.002..0.002 rows=1 loops=541559704)
                                                   Index Cond: (ipaddr >>= (flows.srcaddr)::ip4r)
                                                   Heap Fetches: 59971474
                                                   Buffers: shared hit=996550152
                                       ->  Hash  (cost=19462896.74..19462896.74 rows=11210 width=4) (actual time=1847228.894..1847228.894 rows=3099798 loops=10)
                                             Buckets: 4194304 (originally 16384)  Batches: 1 (originally 1)  Memory Usage: 141746kB
                                             Buffers: shared hit=120036496
                                             ->  HashAggregate  (cost=19462829.48..19462863.11 rows=11210 width=4) (actual time=1230049.015..1845955.764 rows=3099798 loops=10)
                                                   Group Key: flows_1.dstaddr
                                                   Buffers: shared hit=120036496
                                                   ->  Nested Loop Anti Join  (cost=0.12..19182620.78 rows=560417390 width=4) (actual time=0.084..831832.333 rows=113420172 loops=10)
                                                         Join Filter: (mynetworks_1.ipaddr >> (flows_1.dstaddr)::ip4r)
                                                         Rows Removed by Join Filter: 453681377
                                                         Buffers: shared hit=120036496
                                                         ->  Index Only Scan using flows_srcaddr_dstaddr_idx on flows flows_1  (cost=0.12..9091067.70 rows=560978368 width=4) (actual time=0.027..113052.437 rows=541559704 loops=10)
                                                               Heap Fetches: 91
                                                               Buffers: shared hit=120036459
                                                         ->  Materialize  (cost=0.00..1.02 rows=4 width=8) (actual time=0.000..0.000 rows=2 loops=5415597040)
                                                               Buffers: shared hit=10
                                                               ->  Seq Scan on mynetworks mynetworks_1  (cost=0.00..1.01 rows=4 width=8) (actual time=0.007..0.008 rows=4 loops=10)
                                                                     Buffers: shared hit=10
 Planning time: 6.689 ms
 Execution time: 2764860.853 ms
(58 rows)

Regarding "Also using dstat I can see that iowait time is at about 25%", I don't think the server was doing anything else. If it is important, I can repeat the benchmarks.
Thanks!

Charles

Charles,

In your original posting I couldn’t find what value you set for temp_buffers.
Considering you have plenty of RAM, try setting temp_buffers=’6GB’ and then run ‘explain (analyze, buffers) select…’ in the same session. This should alleviate “disk sort’ problem.

Also, could you post the structure of flowscompact, mynetworks, and dstextern tables with all the indexes and number of rows. Actually, are they all – tables, or some of them – views?

Igor


Sorry, I misstated the parameter to change.
It is work_mem (not temp_buffers) you should try to increase to 6GB.

Igor




reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: [email protected]
  Cc: [email protected], [email protected], [email protected]
  Subject: Re: Very poor read performance, query independent
  In-Reply-To: <DM5PR07MB2810C1580B17D1BF15B15AE5DAAF0@DM5PR07MB2810.namprd07.prod.outlook.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by agora; see mirroring instructions
for how to clone and mirror all data and code used for this inbox