powa-team / powa

PostgreSQL Workload Analyzer
http://powa.readthedocs.io/
PostgreSQL License
766 stars 57 forks source link

Strange calculation result #88

Closed trourance closed 7 years ago

trourance commented 7 years ago

Hi, I have updated the powa archivist extension to 3.1.0 and I found this strange calculation result when I try to order by Avg Time. Most probably only the displayed value is wrong, because it puts it on top.

capture du 2017-05-05 16-54-27

rjuju commented 7 years ago

Hi,

That's weird.

What version of powa-web are you using?

Could you compare what the grid displays with this query results? (you have to use your database name instead of DBNAME_HERE)

SELECT anon_1.queryid, powa_statements.query, sum(anon_1.calls) AS calls, sum(anon_1.runtime) AS runtime, sum(anon_1.shared_blks_read * block_size.block_size) AS shared_blks_read, sum(anon_1.shared_blks_hit * block_size.block_size) AS shared_blks_hit, sum(anon_1.shared_blks_dirtied * block_size.block_size) AS shared_blks_dirtied, sum(anon_1.shared_blks_written * block_size.block_size) AS shared_blks_written, sum(anon_1.temp_blks_read * block_size.block_size) AS temp_blks_read, sum(anon_1.temp_blks_written * block_size.block_size) AS temp_blks_written, sum(anon_1.runtime) / greatest(sum(anon_1.calls), 1) AS avg_runtime, sum(anon_1.blk_read_time) AS blks_read_time, sum(anon_1.blk_write_time) AS blks_write_time
FROM (SELECT CAST(current_setting('block_size') AS NUMERIC) AS block_size) AS block_size, (SELECT queryid, dbid, userid, datname, max(calls) - min(calls) AS calls, max(total_time) - min(total_time) AS runtime, max(shared_blks_read) - min(shared_blks_read) AS shared_blks_read, max(shared_blks_hit) - min(shared_blks_hit) AS shared_blks_hit, max(shared_blks_dirtied) - min(shared_blks_dirtied) AS shared_blks_dirtied, max(shared_blks_written) - min(shared_blks_written) AS shared_blks_written, max(temp_blks_read) - min(temp_blks_read) AS temp_blks_read, max(temp_blks_written) - min(temp_blks_written) AS temp_blks_written, max(blk_read_time) - min(blk_read_time) AS blk_read_time, max(blk_write_time) - min(blk_write_time) AS blk_write_time
FROM
    powa_databases,
    LATERAL
    (
        SELECT unnested.dbid, unnested.userid, unnested.queryid,(unnested.records).*
        FROM (
            SELECT psh.dbid, psh.userid, psh.queryid, psh.coalesce_range, unnest(records) AS records
            FROM powa_statements_history psh
            WHERE coalesce_range && tstzrange(now()-interval '1 hour', now(), '[]')
            AND psh.dbid = powa_databases.oid
            AND psh.queryid IN ( SELECT powa_statements.queryid FROM powa_statements WHERE powa_statements.dbid = powa_databases.oid )
        ) AS unnested
        WHERE tstzrange(now()-interval '1 hour', now(), '[]') @> (records).ts
        UNION ALL
        SELECT psc.dbid, psc.userid, psc.queryid,(psc.record).*
        FROM powa_statements_history_current psc
        WHERE tstzrange(now()-interval '1 hour',now(),'[]') @> (record).ts
        AND psc.dbid = powa_databases.oid
        AND psc.queryid IN ( SELECT powa_statements.queryid FROM powa_statements WHERE powa_statements.dbid = powa_databases.oid )
    ) h
     GROUP BY queryid, dbid, userid, datname
HAVING max(calls) - min(calls) > 0) AS anon_1 JOIN powa_statements ON powa_statements.queryid = anon_1.queryid AND powa_statements.userid = anon_1.userid AND powa_statements.dbid = anon_1.dbid
WHERE anon_1.datname = 'DBNAME_HERE' GROUP BY anon_1.queryid, powa_statements.query ORDER BY sum(anon_1.runtime) DESC
trourance commented 7 years ago

Hi,

I'm using powa-web 3.2.1

I have ran the query and the results of it are good. But the results displayed by the grid are wrong, and it seems not only for that particular query.

Look at those new screenshots, for both the grid and the query values.

2017-05-05 20:59 GMT+02:00 Julien Rouhaud notifications@github.com:

Hi,

That's weird.

What version of powa-web are you using?

Could you compare what the grid displays with this query results? (you have to use your database name instead of DBNAME_HERE)

SELECT anon_1.queryid, powa_statements.query, sum(anon_1.calls) AS calls, sum(anon_1.runtime) AS runtime, sum(anon_1.shared_blks_read block_size.block_size) AS shared_blks_read, sum(anon_1.shared_blks_hit block_size.block_size) AS shared_blks_hit, sum(anon_1.shared_blks_dirtied block_size.block_size) AS shared_blks_dirtied, sum(anon_1.shared_blks_written block_size.block_size) AS shared_blks_written, sum(anon_1.temp_blks_read block_size.block_size) AS temp_blks_read, sum(anon_1.temp_blks_written block_size.block_size) AS temp_blks_written, sum(anon_1.runtime) / greatest(sum(anon_1.calls), 1) AS avg_runtime, sum(anon_1.blk_read_time) AS blks_read_time, sum(anon_1.blk_write_time) AS blks_write_timeFROM (SELECT CAST(current_setting('block_size') AS NUMERIC) AS block_size) AS block_size, (SELECT queryid, dbid, userid, datname, max(calls) - min(calls) AS calls, max(total_time) - min(total_time) AS runtime, max(shared_blks_read) - min(shared_blks_read) AS shared_blks_read, max(shared_blks_hit) - min(shared_blks_hit) AS shared_blks_hit, max(shared_blks_dirtied) - min(shared_blks_dirtied) AS shared_blks_dirtied, max(shared_blks_written) - min(shared_blks_written) AS shared_blks_written, max(temp_blks_read) - min(temp_blks_read) AS temp_blks_read, max(temp_blks_written) - min(temp_blks_written) AS temp_blks_written, max(blk_read_time) - min(blk_read_time) AS blk_read_time, max(blk_write_time) - min(blk_write_time) AS blk_write_timeFROM powa_databases, LATERAL ( SELECT unnested.dbid, unnested.userid, unnested.queryid,(unnested.records). FROM ( SELECT psh.dbid, psh.userid, psh.queryid, psh.coalesce_range, unnest(records) AS records FROM powa_statements_history psh WHERE coalesce_range && tstzrange(now()-interval '1 hour', now(), '[]') AND psh.dbid = powa_databases.oid AND psh.queryid IN ( SELECT powa_statements.queryid FROM powa_statements WHERE powa_statements.dbid = powa_databases.oid ) ) AS unnested WHERE tstzrange(now()-interval '1 hour', now(), '[]') @> (records).ts UNION ALL SELECT psc.dbid, psc.userid, psc.queryid,(psc.record). FROM powa_statements_history_current psc WHERE tstzrange(now()-interval '1 hour',now(),'[]') @> (record).ts AND psc.dbid = powa_databases.oid AND psc.queryid IN ( SELECT powa_statements.queryid FROM powa_statements WHERE powa_statements.dbid = powa_databases.oid ) ) h GROUP BY queryid, dbid, userid, datnameHAVING max(calls) - min(calls) > 0) AS anon_1 JOIN powa_statements ON powa_statements.queryid = anon_1.queryid AND powa_statements.userid = anon_1.userid AND powa_statements.dbid = anon_1.dbidWHERE anon_1.datname = 'DBNAME_HERE' GROUP BY anon_1.queryid, powa_statements.query ORDER BY sum(anon_1.runtime) DESC

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/dalibo/powa/issues/88#issuecomment-299548692, or mute the thread https://github.com/notifications/unsubscribe-auth/AGoUKbE0o5XKj4ODQ0k4tnTspamR8nszks5r23GhgaJpZM4NSCFi .

rjuju commented 7 years ago

You probably mean powa-web 3.1.2?

Also, if you attached pictures on your mail, they don't appear here :/

trourance commented 7 years ago

Sorry, yes I meant 3.1.2

capture du 2017-05-08 10-04-18 capture du 2017-05-08 10-04-35

Btw, I found that the time column might have some fancy values, too. Look at the value there. capture du 2017-05-08 15-16-46-2 capture du 2017-05-08 15-17-29-2 capture du 2017-05-08 15-22-56-2

champeric commented 7 years ago

The problem is in the calculation of microseconds in duration.js. The calculation of microsecDiff is inverted because there's a check that m2 >= m1 so it should be m2 - m1 and not m1 -m2.

So the example above gives: microsecDiff = Math.round((1000 * (m1._i - Math.floor(m1)) - 1000 * (m2._i - Math.floor(m2)))) microsecDiff = Math.round((1000 * (0 - 0) - 1000 * (1.795 - 1) = -795 Couple of lines below, if(microsecDiff < 0) microsecDiff = 1000 + (-795) = 205; msecDiff--; // was 1, so now msecDiff = 0

But inverting m1 and m2 is not enough, because the check that m2 >= m1 with isAfter() only seems to compare with milliseconds precision so for values less than 1 ms it would give wrong values so we have to fix that a bit.

I'll do a pull request that seems to give the correct values in my tests, but someone more familiar with the code should double-check or find a cleaner way to do that.

rjuju commented 7 years ago

@champeric nice catch! I'll look into it

rjuju commented 7 years ago

@fluancefg Thanks to @champeric this should now be fixed. Do you have a way to try latest commit in debug mode (like running run_powa.py)? In any case I'll update minified javascript to prepare new release soon.

trourance commented 7 years ago

Hello, Yes, I have a way to try latest commit in debug mode. What do you want me to provide ? The full stack trace ?

rjuju commented 7 years ago

Ok. No running in debug mode is just to use raw javascript that just got updated instead of miinified one. If latest commit does fix this issue for you I'll do a release of powa-web quickly.

trourance commented 7 years ago

Ok. So I have tested the latest commit version and it seems that the calculation display is fixed.

avgtime runtime

rjuju commented 7 years ago

Thanks a lot for checking  @fluancefg

I'll release a new version soon.

rjuju commented 7 years ago

I just published release 3.1.3: https://github.com/dalibo/powa-web/releases/tag/3.1.3 It's also available on pypi.

Thanks @fluancefg and @champeric !

trourance commented 7 years ago

Thanks. Just for info, the doc is still pointing on the old version, and the following command returns a 404:

wget https://pypi.python.org/packages/source/p/powa-web/powa-web-3.1.3.tar.gz

rjuju commented 7 years ago

Oops, I forgot to update it :( It's fixed now.

For pypi, I can see it here: https://pypi.python.org/pypi/powa-web and pip search does find release 3.1.3.

I'm not that much familiar with pypi, so I've no idea if it should be available through this link. Is there any action needed for that?

trourance commented 7 years ago

I can't help you, I don't know anything about pypi. Maybe you should just point to your own github, it's where I picked it

rjuju commented 7 years ago

It turns out pypi changed their API, and human-friendly link are now available through pypi.io instead of pypi.python.org.

I updated the documentation, everything should finally be ok now :)

Thanks a lot for noticing all these issues.

trourance commented 7 years ago

Great, thanks for your good job.