Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Is everything in this request necessary (especially the DROP TABLE)? #45

Open
Oodnadatta opened this issue Feb 3, 2018 · 14 comments
Open
Labels
optimization Issue regarding performance and code optimization question Open question and discussion
Milestone

Comments

@Oodnadatta
Copy link
Member

Optimization

I want to sort data in the analysis table. Request is quite long. I look at the requests below.

First, sort on SYMBOL. It drops the table.

DROP TABLE IF EXISTS wt_7_tmp CASCADE;
CREATE TABLE wt_7_tmp AS
  SELECT ROW_NUMBER() OVER(ORDER BY _5b6c898a867eb9246614fed7fd73ef2a) as page,
    variant_id, 
    array_remove(array_agg(trx_pk_value), NULL) as trx,
    count(trx_pk_value) as trx_count, 
    _5b6c898a867eb9246614fed7fd73ef2a
FROM wt_7
GROUP BY variant_id, _5b6c898a867eb9246614fed7fd73ef2a;

Second, sort on FILTER. It drops the table even though it is almost the same.

DROP TABLE IF EXISTS wt_7_tmp CASCADE;
CREATE TABLE wt_7_tmp AS
  SELECT ROW_NUMBER() OVER(ORDER BY s89_filter #>> '{}') as page,
    variant_id, 
    array_remove(array_agg(trx_pk_value), NULL) as trx,
    count(trx_pk_value) as trx_count, 
    s89_filter #>> '{}'
FROM wt_7
GROUP BY variant_id, s89_filter #>> '{}';

For reference, below is the request which is done in both cases after the creation of the table. It doesn't look like the result will be different.

SELECT ws.variant_id, wt.is_selected, ws.trx_count, wt.vcf_line, wt.chr, wt.pos, wt.ref, wt.alt, wt.s89_gt, wt.s90_gt, wt.s91_gt, wt.s89_dp, wt.s90_dp, wt.s91_dp, wt.s89_dp_alt, wt.s90_dp_alt, wt.s91_dp_alt, wt.s89_qual, wt.s90_qual, wt.s91_qual, wt.s89_filter, wt.s90_filter, wt.s91_filter, wt.regovar_score, wt._c226c0068ff542e6b96e8a547d343769, wt._5b6c898a867eb9246614fed7fd73ef2a, wt.sample_tcount, wt._db6645831e7c4e8122866831bb033cb1, wt._c34d543d6e41fed6c6f2b5880648e5ba, wt._fe8e0aa7569f01b555ea16a1dfb4cc95, wt._b5968c1a27a8955b5b64f83da60a4ecf, wt._5803633f01600a2e047aad3ee2faa133, wt._4a3364a3e728fba77ba24ac0139f11af, wt._8ce3587f7cf3983d5bcc9058a74a8d1e, wt._310648e1b6bb1030c44d63034ced7243, wt._4001d967fcb1d2153872eff7ba36cc2c, wt._518485ecbbcebd1f55c7350f8314e8bc, wt._8409cac61d602ba979a6856a0d7614d4 FROM wt_7_tmp ws INNER JOIN wt_7 wt ON ws.variant_id=wt.variant_id WHERE wt.is_variant AND ws.page>=0 ORDER BY ws.page LIMIT 100;

Secondary sort

Is a secondary sort possible? For example, by first sorting on chr and then by sorting on position.

@ikit
Copy link
Member

ikit commented Feb 5, 2018

The temp table is created to store the result of the query with sorting option and pagination.
So event if you don't modify the filter, but just changing sort option, the temp table will be change.

The secondary sort if supported server side, but the table QML component do not allow it natively.

@ikit ikit self-assigned this Feb 5, 2018
@ikit ikit added the question Open question and discussion label Feb 5, 2018
@Oodnadatta
Copy link
Member Author

Oodnadatta commented Feb 5, 2018

When looking at timing, the first block takes 2300 to 2400 ms (essentially the SELECT).

SELECT
    ROW_NUMBER() OVER(ORDER BY chr) as page,
    variant_id,
    array_remove(array_agg(trx_pk_value), NULL) as trx,
    count(trx_pk_value) as trx_count,
    chr
FROM wt_7
WHERE (filter_1)
GROUP BY variant_id, chr;

The following block (for display) takes 100 ms.

SELECT ws.variant_id, wt.is_selected, ws.trx_count, wt.vcf_line, wt.chr, wt.pos, wt.ref, wt.alt, wt.s89_gt, wt.s90_gt, wt.s91_gt, wt.s89_dp, wt.s90_dp, wt.s91_dp, wt.s89_dp_alt, wt.s90_dp_alt, wt.s91_dp_alt, wt.s89_qual, wt.s90_qual, wt.s91_qual, wt.s89_filter, wt.s90_filter, wt.s91_filter, wt.regovar_score, wt._c226c0068ff542e6b96e8a547d343769, wt._5b6c898a867eb9246614fed7fd73ef2a, wt.sample_tcount, wt._db6645831e7c4e8122866831bb033cb1, wt._c34d543d6e41fed6c6f2b5880648e5ba, wt._fe8e0aa7569f01b555ea16a1dfb4cc95, wt._b5968c1a27a8955b5b64f83da60a4ecf, wt._5803633f01600a2e047aad3ee2faa133, wt._4a3364a3e728fba77ba24ac0139f11af, wt._8ce3587f7cf3983d5bcc9058a74a8d1e, wt._310648e1b6bb1030c44d63034ced7243, wt._4001d967fcb1d2153872eff7ba36cc2c, wt._518485ecbbcebd1f55c7350f8314e8bc, wt._8409cac61d602ba979a6856a0d7614d4
FROM wt_7_tmp ws
INNER JOIN wt_7 wt ON ws.variant_id=wt.variant_id
WHERE wt.is_variant AND ws.page>=0
ORDER BY ws.page
LIMIT 100;

Could we avoid the creation of the table at each sorting or is it possible to optimize the times?

@Arkanosis
Copy link
Member

Arkanosis commented Feb 5, 2018

$ sudo -u regovar psql -d regovar -c "EXPLAIN ANALYZE SELECT ROW_NUMBER() OVER(ORDER BY chr) as page, variant_id, array_remove(array_agg(trx_pk_value), NULL) as
trx, count(trx_pk_value) as trx_count, chr FROM wt_7 WHERE (filter_1) GROUP BY variant_id, chr;"
                                                                QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------
 WindowAgg  (cost=565700.98..573219.04 rows=375903 width=60) (actual time=2051.588..2066.836 rows=29933 loops=1)
   ->  Sort  (cost=565700.98..566640.74 rows=375903 width=52) (actual time=2051.401..2054.481 rows=29933 loops=1)
         Sort Key: chr
         Sort Method: external sort  Disk: 3256kB
         ->  GroupAggregate  (cost=489828.19..518043.87 rows=375903 width=52) (actual time=1993.938..2035.505 rows=29933 loops=1)
               Group Key: variant_id, chr
               ->  Sort  (cost=489828.19..494531.57 rows=1881351 width=26) (actual time=1993.922..2004.529 rows=102351 loops=1)
                     Sort Key: variant_id, chr
                     Sort Method: external merge  Disk: 3184kB
                     ->  Seq Scan on wt_7  (cost=0.00..203733.02 rows=1881351 width=26) (actual time=0.698..1943.727 rows=102351 loops=1)
                           Filter: filter_1
                           Rows Removed by Filter: 3660351
 Planning time: 1.710 ms
 Execution time: 2068.723 ms

@Arkanosis
Copy link
Member

Time is spent scanning all 3.5M rows to filter using “filter_1” everytime the sort criterion is changed. What is “filter_1”, exactly? Could we use some index / cache there?

@Arkanosis
Copy link
Member

Arkanosis commented Feb 5, 2018

Summary:

  • there are 3,762,702 rows in wt_7;
  • 102,351 rows are kept after filtering with filter_1 (whatever this is), using sequential scanning (ie. no index, no optimization) — it takes 1,944ms;
  • these 102,351 rows are sorted on variant_id and chr — it takes 61ms;
  • 29,933 rows are computed by grouping on variant_id and chr — it takes 31ms;
  • these 29,933 rows are sorted on variant_id and chr — it takes 19ms;
  • aggregations are computed on these 29,933 rows — it takes 12ms;
  • overall, it takes ~2,060ms.

I guess (please correct me if I'm wrong) that the filtering step, responsible for ~95% of the runtime, does not yield different results when only the sort criterion changes, meaning that some caching would allow us to shave the runtime down to around 120ms (ie. ~200ms overall, accounting for the ~70ms of the subsequent SELECT).

Maybe doing the grouping / sorting stuff in the SELECT wouldn't cost much more, while at the same time making wt_7_tmp useful only for caching.

@ikit
Copy link
Member

ikit commented Feb 6, 2018

filter_<filter_id> is a boolean column that have been added dynamicaly to the wt table when you save a custom filter (we save the json and this column save the result: "Yes or No the variant/transcript match with the filter").
A first optimization to try is to add an index to these columns when they are added/computed.

If you don't want to regenerate the wt_tmp table on sorting, that means that we don't save this information in the wt_tmp table, so the sorting must be done dynamically each time the client need to retrieve data. that also means that each time we have to first do a join with wt table to retrieve sorted column to then apply the sort and then the limit-offset (pagination)

That will be quick when we have few rows, but it will be longer than the current solution when we have lot of rows...

@ikit
Copy link
Member

ikit commented Feb 19, 2018

@Arkanosis: Do you know if it's possible to set PostgreSQL to create "In-Memory table" like in MySQL. I quickly searched and found that this feature could be done with PostgreSQL 10.

I thinks that creating In-Memory table for wt_{id}_tmp table is the solution to optimize filtering.

@Arkanosis
Copy link
Member

Dunno… Would it be to avoid I/Os? Because I'm actually not convinced we have an I/O issue here. There's so much RAM available on Brownie that everything is most likely in memory already (what I've seen when playing with the above query is that it was CPU-bound). See with a less CPU-intensive query:

Server before:
image

$ sudo -u regovar /usr/bin/time -v psql -d regovar -c "SELECT COUNT(chr) FROM wt_7;" 
  count  
---------
 3762702
(1 ligne)
        Command being timed: "psql -d regovar -c SELECT COUNT(chr) FROM wt_7;"
        User time (seconds): 0.06
        System time (seconds): 0.00
        Percent of CPU this job got: 5%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:01.13
        […]
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 2455
        Voluntary context switches: 22
        Involuntary context switches: 9
        Swaps: 0
        File system inputs: 0
        File system outputs: 0
        […]

(Obviously the client itself doesn't account for much of the runtime. Only a mere 60ms of CPU time).

Server after:
image

Not only there is zero major page fault (ie. actual disk read, CMAJFLT), but the ~1500 minor page faults (ie. mapping of data already in physical memory into the process virtual address space, CMINFLT) account for at most 340ms (CSTIME) of the CPU time (worst case where all of the system CPU time is spent handling minor page faults).

@ikit
Copy link
Member

ikit commented Feb 19, 2018

The problem of performance occure when whe apply a filter, because I drop/create a temps table to hold the result.

So the request to test is more something like this

DROP TABLE IF EXISTS wt_7_tmp CASCADE; CREATE TABLE wt_7_tmp AS SELECT ROW_NUMBER() OVER(ORDER BY vcf_line DESC) as page, variant_id, array_remove(array_agg(trx_pk_value), NULL) as trx, count(trx_pk_value) as trx_count, vcf_line FROM wt_7  GROUP BY variant_id, vcf_line;

I test this command like you, but I do not understand what i'm monitoring ...

$ sudo -u regovar /usr/bin/time -v psql -d regovar -c "DROP TABLE IF EXISTS wt_7_tmp CASCADE; CREATE TABLE wt_7_tmp AS SELECT ROW_NUMBER() OVER(ORDER BY vcf_line DESC) as page, variant_id, array_remove(array_agg(trx_pk_value), NULL) as trx, count(trx_pk_value) as trx_count, vcf_line FROM wt_7  GROUP BY variant_id, vcf_line;" 
SELECT 583632
        Command being timed: "..."
        User time (seconds): 0.05
        System time (seconds): 0.02
        Percent of CPU this job got: 9%
        Elapsed (wall clock) time (h:mm:ss or m:ss): 0:06.90
        […]
        Major (requiring I/O) page faults: 0
        Minor (reclaiming a frame) page faults: 2465
        Voluntary context switches: 22
        Involuntary context switches: 7
        Swaps: 0
        File system inputs: 0
        File system outputs: 0
        […]

Where do you see that we are bound by the CPU ? we only use 9% ?

Are you sure that write access are monitored by this tool ?
Because I didn't see any write access with my command... so he didn't store the created table on the disk ? However I'm pretty sure that if I restart the server I will retrieve the table wt_7_tmp..

@Arkanosis
Copy link
Member

So the request to test is more something like this

Yeah, but it's the SELECT in it that takes most of the time. If you remove the DROP and the CREATE, it doesn't get much faster. Hence timings for the SELECT alone starting from my first comment in this thread.

I test this command like you, but I do not understand what i'm monitoring ...

You're monitoring the client. It takes 6.9 seconds from the time you press enter to the moment you get your prompt back, uses the CPUs during 50ms to run the client code and 20ms to run the Linux kernel code. It makes no I/O (see major faults), yet accesses data that is not yet mapped in the client process' address space 2465 times (could have been as many I/Os, but data was already in RAM).

The most important information you get here, is that the client is responsible for almost nothing time-wise.

Most time is actually spent by the server processes, which you can monitor using htop. Substract CUTIME before the SELECT from CUTIME after the SELECT, and you get how much time has been spent using the CPUS in all the main pg process' children. Do the same with CSTIME for the time spent in the Linux kernel.

Here, for ~1mn of wall clock time measured at the client, we're spending ~1mn running pg's server processes on the CPUs. Assuming only one core is used (I'm pretty sure that's the case), this means pretty much all the time is spent waiting for the CPU.

Also note that I've simplified the SELECT; the original one is even more CPU-intensive (I would have used it, but filter_1 was not available anymore).

@ikit
Copy link
Member

ikit commented Feb 19, 2018

Ok thanks for the explanations.

So my test with default pg server settings take 6 seconds.
By allocating more memory to this query : SET LOCAL work_mem = '1GB'
I reduced execution time to 3 seconds. Because thanks to that, the sort and the grouping operations are done quickly in RAM without "External merge disk operation".

The remaining 3s are all spent in the sequencial scan of all entry of the table wt_7.
-> Brownie need 3s to read the 3 762 767 entries of the table wt_7... (pfff the noob)

For additional optimization, we have to change the "regovar workflow" and how/when data are processed.

The sequential scan of all entries is done because I read all variants and their transcripts (only to know how many transcript match by variant to be able to display in the treeView the icon that indicates that the entry have sub-entries).
(Note: 3762767 entries in wt_7 but only 583 632 variants)

But as the user don't need transcript's information in a first time (they work only at hight level with gene/variant and check transcripts only they found an interesting variant). We could assume that we display the icon for subentries in the treeview everytime, and then trying to retrieving variant's transcripts only when requested by the user...

ikit pushed a commit that referenced this issue Feb 19, 2018
@Oodnadatta
Copy link
Member Author

When Arkanosis did the test, he didn't have the same results: tuning postgresql's settings to use quicksort instead of external merge sort didn't result in any significant improvement in the Arkanosis tests (but it was only taking around 2 seconds overall). Nevertheless the nearly same tuning by Ikit (SET LOCAL work_mem = '1GB') leads to a 2x improvement.
Arkanosis and Ikit, are you working on the same data?
Ikit, have you done this test on Brownie or on another machine?

@ikit
Copy link
Member

ikit commented Feb 20, 2018

I'm testing like you on Brownie with wt_7. But this table have been regenerated between Arkanosis test and mine (that's probably why few additionnal transcript have been found...).
But in his test Arkanosis filter on filter_1 field, while I do not apply any filter.

No big change since Feb 5th regarding data generation wt_:

  • de novo computation
  • specifying btree method at index creation for some fields
  • using UNLOGGED tables

Note also that planning/execution may differ a little between each execution the command:

$ sudo -u regovar psql -d regovar -c "DROP TABLE IF EXISTS wt_7_tmp CASCADE; EXPLAIN ANALYZE CREATE UNLOGGED TABLE wt_7_tmp AS SELECT ROW_NUMBER() OVER(ORDER BY vcf_line ASC) as page, variant_id, array_remove(array_agg(trx_pk_value), NULL) as trx, count(trx_pk_value) as trx_count, vcf_line FROM wt_7  GROUP BY variant_id, vcf_line;" 

I just run the command 5 times and it took between ~ 4900ms and 5400ms.

@Arkanosis
Copy link
Member

Arkanosis filter on filter_1 field, while I do not apply any filter

Oh yes, that's probably it. You're sorting / grouping many more results than I was.

@ikit ikit removed their assignment Feb 22, 2018
@ikit ikit added this to the RC 1 milestone Feb 22, 2018
@ikit ikit added the optimization Issue regarding performance and code optimization label Feb 22, 2018
@Oodnadatta Oodnadatta modified the milestones: Beta1, 0.14.0 Jun 27, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
optimization Issue regarding performance and code optimization question Open question and discussion
Projects
None yet
Development

No branches or pull requests

3 participants