powa-team / powa-web

PoWA user interface
http://powa.readthedocs.io/
73 stars 30 forks source link

database statements (details) are missing #18

Closed arlt closed 7 years ago

arlt commented 7 years ago

Hi,

we use a schema with the same name as the database: testdb - i don't know why, but i am sure, that i have no chance, that we change this.

I use pgreplay to replay the SQL statements:

postgres@testit:~$ time pgreplay -c -j /tmp/postgresql-2016-10-07_122541.csv;
Do 13. Okt 12:25:45 CEST 2016

Parse statistics
================

Log lines read: 17430
Total SQL statements processed: 4349
Simple SQL statements processed: 22
Parametrized SQL statements processed: 1630
Named prepared SQL statements executions processed: 2697
Different named prepared SQL statements processed: 84
(average reuse count 31.107)
Cancel requests processed: 0
Fast-path function calls ignored: 0

Replay statistics
=================

Speed factor for replay: 1.000
Total run time: 54.799 seconds
Maximum lag behind schedule: 1 seconds
Calls to the server: 6155
(112.320 calls per second)
Total number of connections: 47
Maximum number of concurrent connections: 5
Average number of concurrent connections: 1.554
Average session idle percentage: 37.538%
SQL statements executed: 4348
(3 or 0.069% of these completed with error)
Maximum number of concurrent SQL statements: 2
Average number of concurrent SQL statements: 0.971
Average SQL statement duration: 0.009 seconds
Maximum SQL statement duration: 38.912 seconds
Statement duration histogram:
  0    to 0.02 seconds: 97.624%
  0.02 to 0.1  seconds: 1.287%
  0.1  to 0.5  seconds: 1.072%
  0.5  to 2    seconds: 0.000%
     over 2    seconds: 0.016%

real    0m54.817s
user    0m10.068s
sys 0m17.276s

In http://localhost:8888/overview/ i can see the database 'testdb' only with 1 call. After some time and a reload, i can see 3625 calls.

If i select the database (http://localhost:8888/database/testdb/overview/), i can't see any SQL statement.

Again, if i wait some time ... i can see 9 statements (ROLLBACK on top with 4 calls) - presumably from public schema:

ROLLBACK
SELECT CAST(? AS VARCHAR(60)) AS anon_1
show transaction isolation level
select current_schema()
select version()
SELECT t.oid, typarray FROM pg_type t JOIN pg_namespace ns ON typnames
show standard_conforming_strings
SELECT extversion FROM pg_extension WHERE extname = ? LIMIT ?
SELECT ? AS some_label

Filtering works, but i can only see those statements above.

If i manually enter a query, i can't see it in powa-web, too - regardless of the timerange. The statements can be found in the powa database (powa_statements_history_current). The corresponding queryid can be found in powa_statements.

Example:

postgres@testsrv:~$ psql testdb
psql (9.5.4)
Type "help" for help.

testdb=# select * from testdb.table;
.... data
(6 rows)

testdb=# \c powa
powa=# select * from powa_statements where query ilike 'select %table%';
  queryid   | dbid  | userid |                query                
------------+-------+--------+-------------------------------------
 2404330049 | 55028 |     10 | select * from testdb.table
powa=# select * from powa_statements_history_current where queryid=2404330049;
  queryid   | dbid  | userid |                                 record                                  
------------+-------+--------+-------------------------------------------------------------------------
 2404330049 | 55028 |     10 | ("2016-10-13 14:06:24.962028+02",52,1.923,312,52,0,0,0,0,0,0,0,0,0,0,0)
(1 row)
powa=# select * from powa_databases ;
  oid  |  datname  | dropped 
-------+-----------+---------
     1 | template1 | 
 12420 | template0 | 
 12425 | postgres  | 
 55028 | testdb    | 
 58447 | powa      | 
(5 rows)

Did i miss something?!

# versions
Ubuntu 16.04
PostgreSQL 9.5
powa-archivist 3.1
powa-web 3.1
pg_qualstats-master from today
pg_stat_kcache-master from today

# powa database
powa=# \dx
                                     List of installed extensions
        Name        | Version |   Schema   |                        Description                        
--------------------+---------+------------+-----------------------------------------------------------
 btree_gist         | 1.1     | public     | support for indexing common datatypes in GiST
 pg_qualstats       | 1.0.1   | public     | An extension collecting statistics about quals
 pg_stat_kcache     | 2.0.3   | public     | Kernel statistics gathering
 pg_stat_statements | 1.3     | public     | track execution statistics of all SQL statements executed
 plpgsql            | 1.0     | pg_catalog | PL/pgSQL procedural language
 powa               | 3.1.0   | public     | PostgreSQL Workload Analyser-core
(6 rows)

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements,powa,pg_qualstats,pg_stat_kcache'
track_io_timing = on

# pg_hba.conf
local   all             all                                     trust
host    all             all             127.0.0.1/32            trust
host    all             all             ::1/128                 trust
host all all 0.0.0.0/0 trust

Kind regards Michael

rjuju commented 7 years ago

Hello,

Having to wait a little is expected, it's showing evolution of data, so you need at least two snapshot to see something (so with default settings, 10 minutes).

For the lack of query in the per-database view, I think the problem comes from here:

Speed factor for replay: 1.000 Total run time: 54.799 seconds

With current design of powa, queries that are only executed between two snapshots and never again won't be displayed in the per-database. This is usually not a problem since you don't want to analyze stuff that'll never be run again, but in your case if you want to perform some analysis on the replayed activity (I presume this is not production database), I think the easiest way is to configure powa.frequency more aggressively, like 5s.

arlt commented 7 years ago

Thanks - great hint(s). In a first try i removed parameter '-j' and set powa.frequency to 5s. Works.