Performance Engineering Tools & References

Eclipse memory analyzer tool quick guide: https://eclipsesource.com/blogs/2013/01/21/10-tips-for-using-the-eclipse-memory-analyzer/

Postgresql Client: https://blog.devart.com/meet-the-most-anticipated-client-ever-for-postgresql-developers.html?utm_source=groups&utm_medium=social&utm_campaign=buffer&utm_content=product-release-studio-postgresql

PostgreSQL Internals: http://www.interdb.jp/pg/index.html
https://social.technet.microsoft.com/wiki/contents/articles/1515.perfguide-user-mode-versus-privileged-mode-processor-usage.aspx

Networking Concepts: https://hpbn.co/

Linux Commands: https://wiki.smartos.org/display/DOC/The+Linux-to-SmartOS+Cheat+Sheet

PostgreSQL - pg_stat_statements

Enable pg_stat_statements

1. Open postgresql.conf.
2. Search of 'shared_preload_libraries' parameter and set it to 'pg_stat_statements'.
         shared_preload_libraries = 'pg_stat_statements'
    pg_stat_statements.track = all
3. Save the file and restart services.
4. Connect using pgadmin and check for pg_stat_statements extension.

    SELECT *

FROM

       pg_available_extensions

WHERE

       name = 'pg_stat_statements'

       and installed_version is not null

5. If there is no extension, create one.

   CREATE EXTENSION pg_stat_statements;

6. Check, whether enabled

        SELECT * FROM pg_stat_statements

Reset statistics counters

Reset statistics counters

SELECT pg_stat_statements_reset();

Reset statistics counters

SELECT pg_stat_reset();

All Statements

SELECT query AS "Query_Text",

calls AS "Execution_Count",

total_time AS "Total_Execution_Time(ms)",

round((100 * total_time /

    sum(total_time::numeric) OVER ())::numeric, 2) AS "Percentage_Time(%)", 

shared_blks_hit AS "Total_Cache_Hits(Shared_Blocks)",

shared_blks_read AS "Total_Reads(Shared_Blocks)",

CASE calls

WHEN 0 THEN 0

ELSE blk_read_time / calls 

END AS "ReadTime_Per_Query",

CASE rows 

WHEN 0 THEN 0

ELSE blk_read_time / rows 

END AS "ReadTime_Per_Row",

blk_read_time AS "Total_Read_Time(ms)",

shared_blks_written AS "Total_Writes(Shared_Blocks)",

CASE calls

WHEN 0 THEN 0

ELSE blk_write_time / calls 

END AS "WriteTime_Per_Query",

CASE rows 

WHEN 0 THEN 0

ELSE blk_write_time / rows 

END AS "WriteTime_Per_Row",

blk_write_time AS "Total_Write_Time(ms)",

shared_blks_dirtied AS "Total_Dirtied(Shared_Blocks)",

temp_blks_read AS "TempReads(Blocks)",

temp_blks_written AS "TempWrites(Blocks)",

local_blks_hit AS "Total_Cache_Hits(Local_Blocks)",

local_blks_read AS "Total_Reads(Local_Blocks)",

local_blks_written AS "Total_Writes(Local_Blocks)",

local_blks_dirtied AS "Total_Dirtied(Local_Blocks)"

FROM pg_stat_statements

ORDER BY "Percentage_Time(%)" DESC

SQL ordered by executions

SELECT  roles.rolname, 
statements.query AS "Query_Text",
statements.calls AS "Execution_Count",
statements.total_time AS "Total_Execution_Time(ms)"
FROM pg_stat_statements AS statements
INNER JOIN pg_stat_database AS db ON db.datid = statements.dbid
INNER JOIN pg_roles AS roles ON roles.oid = statements.userid
-- WHERE  db.datname = 'nimbus_0_production' AND roles.rolname NOT LIKE '%backup' AND statements.query NOT LIKE '%FROM pg_%' AND roles.rolname IN ('nimbus', 'wfs') AND statements.query NOT LIKE '%from pg_%'
ORDER BY statements.calls DESC

LIMIT 50

SQL ordered by elapsed time

SELECT  roles.rolname, 
statements.query AS "Query_Text",
statements.total_time AS "Total_Execution_Time(ms)",
CASE statements.calls 
WHEN 0 then 0
ELSE statements.total_time / statements.calls 
END AS "TimePerExecution(ms)",
round((100 * statements.total_time /
        sum(statements.total_time::numeric) OVER ())::numeric, 2) AS "Percentage_Time(%)",
        statements.calls AS "Execution_Count"
FROM pg_stat_statements AS statements
INNER JOIN pg_stat_database ON pg_stat_database.datid = statements.dbid
INNER JOIN pg_roles roles ON roles.oid = statements.userid
-- WHERE pg_stat_database.datname = 'nimbus_0_production' AND roles.rolname NOT LIKE '%backup' AND statements.query NOT LIKE '%FROM pg_%' AND roles.rolname IN ('nimbus', 'wfs') AND statements.query NOT LIKE '%from pg_%'
ORDER BY "Percentage_Time(%)" DESC
LIMIT 50

SQL with highest disk reads 

SELECT  rolname, 
query AS "Query_Text",
total_time  AS "Total_Execution_Time(ms)",
(COALESCE(shared_blks_read,0) +  COALESCE(local_blks_read,0) +  COALESCE(temp_blks_read,0)) AS "Total_Reads(Blocks)",
statements.blk_read_time AS "Total_Read_Time(ms)",
CASE calls
 WHEN 0 THEN 0
 ELSE (COALESCE(shared_blks_read,0) +  COALESCE(local_blks_read,0) +  COALESCE(temp_blks_read,0)) / calls 
END AS "ReadTime_Per_Query"
FROM pg_stat_statements AS statements
INNER JOIN pg_stat_database ON pg_stat_database.datid = statements.dbid
INNER JOIN pg_roles roles ON roles.oid = userid
-- WHERE pg_stat_database.datname = 'nimbus_0_production' AND rolname NOT LIKE '%backup' AND query NOT LIKE '%_pg%'
ORDER BY "Total_Reads(Blocks)" DESC

LIMIT 50

SQL with highest disk writes

SELECT  rolname, 
query AS "Query_Text",
total_time AS "Total_Execution_Time(ms)",
(COALESCE(shared_blks_written,0) +  COALESCE(local_blks_written,0) +  COALESCE(temp_blks_written,0)) AS "Total_Writes(Blocks)",
statements.blk_read_time AS "Total_Write_Time(ms)",
CASE calls
WHEN 0 THEN 0
ELSE (COALESCE(shared_blks_written,0) +  COALESCE(local_blks_written,0) +  COALESCE(temp_blks_written,0)) / calls 
END AS "WriteTime_Per_Query"
FROM pg_stat_statements AS statements
INNER JOIN pg_stat_database ON pg_stat_database.datid = statements.dbid
INNER JOIN pg_roles roles ON roles.oid = userid
--  WHERE pg_stat_database.datname = 'nimbus_0_production' AND rolname NOT LIKE '%backup' AND query NOT LIKE '%_pg%'
ORDER BY "Total_Writes(Blocks)" DESC
LIMIT 50

PostgreSQL Monitoring

Database level

Note: Stats collected by below queries are cumulative results i.e. If you want to check activity stats of an operation, then you have to consider stats before and after performing the operation.

Database - Transaction history / deadlocks detected

Following query gives information about no. of transaction rollbacks, commits and deadlocks detected in each database in the server.

SELECT 
    pg_stat_database.datname AS DBName,
 xact_commit AS "Transaction_Commits",
 xact_rollback AS "Transaction_Rollbacks",
 CASE (xact_commit + xact_rollback) 
  WHEN 0 THEN NULL
  ELSE xact_commit::float/(xact_commit + xact_rollback) 
 END AS "Successful_Transaction_ratio",
 deadlocks AS "Deadlocks_Detected",
 confl_deadlock AS "Queries_Cancelled_With_Deadlock",
 stats_reset AS "Stats_collection_starttime",
 ( clock_timestamp() - stats_reset ) AS "StatsDuration(HH_MM_SS_sss)"
FROM pg_stat_database
INNER JOIN pg_stat_database_conflicts
ON pg_stat_database_conflicts.datname = pg_stat_database.datname
ORDER BY "Successful_Transaction_ratio" ASC

Analysis tips:

1. successful_Transaction_ratio should be close to 1.
2. check if no. of TransactionRollbacks is equal to deadlocks detected.
3. If you encounter deadlocks in the stats refer Deadlocks in PostgreSQL for understanding locking and deadlocks.
4. For difference between Index sequential scan and Bitmap scan refer Index Scan VS Bitmap Scan

Database - Disk & Row read Latency

SELECT  datname AS "DBName",
 tup_inserted AS "Rows_Inserted",
 tup_updated AS "Rows_Updated",
 tup_deleted AS "Rows_Deleted",
 tup_returned AS "Rows_Fetched(FromSequentialScan)",
 tup_fetched  AS "Rows_Fetched(FromBitmapScan)",
 pg_size_pretty( pg_database_size(datname)) AS "Size",
 blk_write_time AS "TotalDiskWriteTime(ms)",
 stats_reset AS "Stats_collection_starttime",
 ( clock_timestamp() - stats_reset ) AS "StatsDuration(HH_MM_SS_sss)"
FROM pg_stat_database
ORDER BY "Rows_Inserted"

Database - IO Performance

Following query gives information about disk activity at database level in the server.

SELECT datname AS DBName,
blks_read AS "TotalDiskReads(Blocks)",
blk_read_time AS "TotalDiskReadTime(ms)",
CASE blks_read
WHEN 0 THEN 0
ELSE (blk_read_time / blks_read )
END AS "AvgDiskReadTime(ms)FromStatsReset",
blk_write_time AS "TotalDiskWriteTime(ms)",
( clock_timestamp() - stats_reset ) AS "StatsDuration(HH_MM_SS_sss)"
FROM pg_stat_database

Analysis tips: 

1. Correlate machine disk activity with database level disk activity

Cache Usage

Following query gives cache hit details (MS SQL Server logical reads equivalent)

SELECT datname AS DBName, 

blks_read AS "DiskReads(Blocks)",

blks_hit AS "Cachehits(Blocks)",

CASE (blks_read + blks_hit)

WHEN 0 THEN 0

ELSE blks_hit::float/(blks_read + blks_hit)

END AS "CacheHitRatio"

FROM pg_stat_database

Analysis tips: 

1. CacheHitRatio value should be close to 1

Temp Files Usage

Following query gives temp files usage i.e. files used for sorting operations

SELECT datname AS DBName, 
 temp_files AS "Temp_Files",

temp_bytes AS "Temp_Files_Size(Bytes)"

FROM pg_stat_database

Analysis tips: 

1. If there is drastic increase in usage of temp files, it may happen that huge number of sorting operations are happening and may require index creation.

Table Level

Operations performed on table & IO

SELECT pg_stat_user_tables.relname AS "TableName",
    ( COALESCE(heap_blks_read,0) + COALESCE(idx_blks_read,0) + COALESCE(toast_blks_read,0) + COALESCE(tidx_blks_read,0)) AS "TotalDiskReads(Blocks)",
( COALESCE(heap_blks_hit,0) + COALESCE(idx_blks_hit,0) + COALESCE(toast_blks_hit,0) + COALESCE(tidx_blks_hit,0) ) AS "TotalCachHits",
    heap_blks_read AS "DiskReads_Data(Blocks)",
heap_blks_hit AS "CacheHits_Data",
idx_blks_read AS "DiskReads_Index(Blocks)",
idx_blks_hit AS "CacheHits_Index",
toast_blks_read AS "DiskReads_ToastData(Blocks)",
toast_blks_hit AS "CachHits_ToastData(Blocks)",
tidx_blks_read AS "DiskReads_ToastIndex(Blocks)",
tidx_blks_hit AS "CacheHits_ToastIndex(Blocks)",
n_tup_ins AS "RowsInserted",
n_tup_upd AS "RowsUpdated",
n_tup_del AS "RowsDeleted",
n_tup_hot_upd AS "RowsUpdated(HOT)",
n_live_tup AS "LiveRows",
n_dead_tup AS "DeadRows"
FROM pg_stat_user_tables 
INNER JOIN pg_statio_user_tables 
ON pg_statio_user_tables.relid = pg_stat_user_tables.relid

Analysis tips: 

1. Identify table with huge sequential scans and try to create index to the columns.

Index Usage in table

SELECT relname AS "TableName",

seq_scan AS "SequentialScans",

seq_tup_read AS "RowsFetched(SequentialScans)",

idx_scan AS "IndexScans",

idx_tup_fetch AS "RowsFetched(IndexScans)"

FROM pg_stat_user_tables 

ORDER BY "SequentialScans" DESC

SELECT 

relname AS "Table",

indexrelname AS "Index",

idx_scan AS "Scans(WithIndex)",

idx_tup_read AS "IndexRows_Read",

idx_tup_fetch AS "TableRowsRead(UsingIndex)"

FROM pg_stat_user_indexes 

ORDER BY "Scans(WithIndex)" ASC

Analysis tips: 

1. Identify unused index with 2nd query.

Vacuum and Analyze

SELECT relname AS "TableName",

vacuum_count AS "Vacuumed(Manual)",

autovacuum_count AS "Vacuumed(Auto)",

analyze_count AS "Analyzed(Manual)",

autoanalyze_count "Analyzed(Auto)",

last_vacuum AS "LastVacuum(Manual)",

last_vacuum AS "LastAutoVacuum(Auto)",

last_analyze AS "LastAnalyzed(Manual)",

last_autoanalyze AS "LastAnalyzed(Auto)",

n_mod_since_analyze AS "RowsModified(AfterAnalyze)"

FROM pg_stat_all_tables 

References
Tracking IO stats   https://malisper.me/track_io_timing/