Performance degradation in 324577f39bc8738ed0ec24c36c5cb2c2f81ec660 - Mailing list pgsql-performance
| From | Vladimir Kamarzin |
|---|---|
| Subject | Performance degradation in 324577f39bc8738ed0ec24c36c5cb2c2f81ec660 |
| Date | |
| Msg-id | 29191412676815@web25o.yandex.ru Whole thread Raw |
| Responses |
Re: Performance degradation in 324577f39bc8738ed0ec24c36c5cb2c2f81ec660
(Tom Lane <tgl@sss.pgh.pa.us>)
|
| List | pgsql-performance |
After upgrade from 9.3.1 to 9.3.5 we expirienced a slight performance degradation of all queries. Query time increased tosome amount of ms, mostly in range of 100ms. Some actions in our application results in a lot of small queries and in suchcases performance degradation is very significant - total action performs for a 2-3 times longer then before (15s ->40s, etc). Using git-bisect we've found a bad revision causes performance drop: it is 324577f39bc8738ed0ec24c36c5cb2c2f81ec660 All tests were performed on the same server with same postgresql.conf, the only load on this server is postgresql test setup. Here is example query plan of one query: http://explain.depesz.com/s/CWA Anecdotally, when such a query executed in psql, it shows different results than when executes as a part of application-inducedbatch of queries. For example, the above query takes 24ms on "fast" postgres version, and 80ms on "slow"postgres versions. But when executed in "standalone" mode from psql, it takes 9.5-13 ms independently on postgres version.So we're logged all statements from our test suite using auto_explain module. Here is query time difference on different postgresql versions: # grep "duration: " 9.3-fast.log |awk '{sum += $6}; END { print sum}' 8309.05 # grep "duration: " 9.3.5.log |awk '{sum += $6}; END { print sum}' 24142 Log from postgres from 1 revision before bad: http://tgt72.ru/static/tmp/9.3-fast.log Log from 9.3.5: http://tgt72.ru/static/tmp/9.3.5.log Database schema: http://tgt72.ru/static/tmp/gits.sql postgresql.conf: data_directory = '/var/lib/postgresql/9.3/main' # use data in another directory hba_file = '/etc/postgresql/9.3/main/pg_hba.conf' # host-based authentication file ident_file = '/etc/postgresql/9.3/main/pg_ident.conf' # ident configuration file external_pid_file = '/var/run/postgresql/9.3-main.pid' # write an extra PID file listen_addresses = '*' # what IP address(es) to listen on; port = 5432 # (change requires restart) unix_socket_directories = '/var/run/postgresql' # comma-separated list of directories ssl = true # (change requires restart) ssl_cert_file = '/etc/ssl/certs/ssl-cert-snakeoil.pem' # (change requires restart) ssl_key_file = '/etc/ssl/private/ssl-cert-snakeoil.key' # (change requires restart) vacuum_cost_delay = 50 vacuum_cost_page_hit = 0 vacuum_cost_limit = 600 fsync = on # turns forced synchronization on or off synchronous_commit = off # synchronization level; log_line_prefix = '%t:%r:%u@%d:[%p]: ' log_statement = 'none' # none, ddl, mod, all log_timezone = 'localtime' autovacuum_max_workers = 4 autovacuum_vacuum_scale_factor = 0.0195 autovacuum_analyze_scale_factor = 0.05 autovacuum_freeze_max_age = 1000000000 autovacuum_vacuum_cost_limit = 300 vacuum_freeze_table_age = 500000000 datestyle = 'iso, dmy' timezone = 'localtime' client_encoding = utf8 # actually, defaults to database lc_messages = 'en_US.UTF-8' # locale for system error message lc_monetary = 'ru_RU.UTF-8' # locale for monetary formatting lc_numeric = 'ru_RU.UTF-8' # locale for number formatting lc_time = 'ru_RU.UTF-8' # locale for time formatting default_text_search_config = 'pg_catalog.russian' max_locks_per_transaction = 128 # min 10 default_statistics_target = 50 # pgtune wizard 2013-11-20 maintenance_work_mem = 1GB # pgtune wizard 2013-11-20 constraint_exclusion = on # pgtune wizard 2013-11-20 checkpoint_completion_target = 0.9 # pgtune wizard 2013-11-20 effective_cache_size = 12GB # pgtune wizard 2013-11-20 work_mem = 96MB # pgtune wizard 2013-11-20 wal_buffers = 8MB # pgtune wizard 2013-11-20 checkpoint_segments = 24 shared_buffers = 4GB # pgtune wizard 2013-11-20 max_connections = 300 # pgtune wizard 2013-11-20 shared_preload_libraries = 'auto_explain' auto_explain.log_analyze = 1 auto_explain.log_min_duration = 0 auto_explain.log_buffers = 1 auto_explain.log_nested_statements = 1 Here is number of tuples estimation: SELECT relname,reltuples::numeric FROM pg_class order by reltuples DESC limit 100; relname | reltuples -----------------------------------------------------------+----------- schedule_line_audit_2013_06_time_fact_idx | 80649500 schedule_line_audit_2013_06_checkpoint_idx | 80649500 schedule_line_audit_2013_06_audit_timestamp_idx | 80649500 schedule_line_audit_2013_06_time_plan_idx | 80649500 schedule_line_audit_2013_06_pk | 80649500 schedule_line_audit_2013_06 | 80649500 schedule_line_audit_2013_06_schedule_end_datetime_idx | 80649500 schedule_line_audit_2013_06_id_idx | 80649500 tl_detector_zone_history_zone_id | 38235000 tl_detector_zone_history | 38235000 tl_detector_zone_history_pkey | 38235000 tl_detector_zone_history_datetime | 38235000 matching_matchingevent_2014_07_pk | 36870100 matching_matchingevent_2014_07 | 36870100 matching_matchingevent_2014_07_start_datetime_idx | 36870100 matching_matchingevent_2014_07_user_ignored_idx | 36870100 matching_matchingevent_2014_07_device_datetime_unique_idx | 36870100 matching_matchingevent_2014_07_device_idx | 36870100 matching_matchingevent_2014_09_start_datetime_idx | 36453900 matching_matchingevent_2014_09_user_ignored_idx | 36453900 matching_matchingevent_2014_09_device_datetime_unique_idx | 36453900 matching_matchingevent_2014_09_pk | 36453900 matching_matchingevent_2014_09 | 36453900 matching_matchingevent_2014_09_device_idx | 36453900 matching_matchingevent_2014_08_device_datetime_unique_idx | 36102100 matching_matchingevent_2014_08_device_idx | 36102100 matching_matchingevent_2014_08 | 36102100 matching_matchingevent_2014_08_start_datetime_idx | 36102100 matching_matchingevent_2014_08_user_ignored_idx | 36102100 matching_matchingevent_2014_08_pk | 36102100 schedule_line_audit_2013_03_schedule_end_datetime_idx | 30608400 schedule_line_audit_2013_03 | 30608400 schedule_line_audit_2013_03_audit_timestamp_idx | 30608400 schedule_line_audit_2013_03_time_fact_idx | 30608400 schedule_line_audit_2013_03_checkpoint_idx | 30608400 schedule_line_audit_2013_03_pk | 30608400 schedule_line_audit_2013_03_id_idx | 30608400 schedule_line_audit_2013_03_time_plan_idx | 30608400 schedule_line_audit_2014_07_checkpoint_idx | 29604500 schedule_line_audit_2014_07_time_plan_idx | 29604500 schedule_line_audit_2014_07_time_fact_idx | 29604500 schedule_line_audit_2014_07_pk | 29604500 schedule_line_audit_2014_07 | 29604500 schedule_line_audit_2014_07_id_idx | 29604500 schedule_line_audit_2014_07_audit_timestamp_idx | 29604500 schedule_line_audit_2014_07_schedule_end_datetime_idx | 29604500 schedule_line_audit_2014_09_id_idx | 28739900 schedule_line_audit_2014_09_audit_timestamp_idx | 28739900 schedule_line_audit_2014_09_schedule_end_datetime_idx | 28739900 schedule_line_audit_2014_09_time_fact_idx | 28739900 schedule_line_audit_2014_09_checkpoint_idx | 28739900 schedule_line_audit_2014_09_pk | 28739900 schedule_line_audit_2014_09_time_plan_idx | 28739900 schedule_line_audit_2014_09 | 28739900 matching_matchingevent_2014_06 | 27963800 matching_matchingevent_2014_06_user_ignored_idx | 27963800 matching_matchingevent_2014_06_device_idx | 27963800 matching_matchingevent_2014_06_pk | 27963800 matching_matchingevent_2014_06_start_datetime_idx | 27963800 matching_matchingevent_2014_06_device_datetime_unique_idx | 27963800 schedule_line_audit_2014_08 | 27197700 schedule_line_audit_2014_08_checkpoint_idx | 27197700 schedule_line_audit_2014_08_schedule_end_datetime_idx | 27197700 schedule_line_audit_2014_08_pk | 27197700 schedule_line_audit_2014_08_time_plan_idx | 27197700 schedule_line_audit_2014_08_time_fact_idx | 27197700 schedule_line_audit_2014_08_id_idx | 27197700 schedule_line_audit_2014_08_audit_timestamp_idx | 27197700 matching_matchingevent_2014_05_user_ignored_idx | 26968500 matching_matchingevent_2014_05_pk | 26968500 matching_matchingevent_2014_05_device_idx | 26968500 matching_matchingevent_2014_05_device_datetime_unique_idx | 26968500 matching_matchingevent_2014_05 | 26968500 matching_matchingevent_2014_05_start_datetime_idx | 26968500 schedule_line_audit_2014_06_audit_timestamp_idx | 25498800 schedule_line_audit_2014_06_time_plan_idx | 25498800 schedule_line_audit_2014_06_schedule_end_datetime_idx | 25498800 schedule_line_audit_2014_06_time_fact_idx | 25498800 schedule_line_audit_2014_06_id_idx | 25498800 schedule_line_audit_2014_06_pk | 25498800 schedule_line_audit_2014_06 | 25498800 schedule_line_audit_2014_06_checkpoint_idx | 25498800 schedule_line_audit_2013_08_audit_timestamp_idx | 25396100 schedule_line_audit_2013_08_pk | 25396100 schedule_line_audit_2013_08_time_plan_idx | 25396100 schedule_line_audit_2013_08_schedule_end_datetime_idx | 25396100 schedule_line_audit_2013_08_id_idx | 25396100 schedule_line_audit_2013_08_time_fact_idx | 25396100 schedule_line_audit_2013_08_checkpoint_idx | 25396100 schedule_line_audit_2013_08 | 25396100 schedule_line_audit_2014_05_id_idx | 24859700 schedule_line_audit_2014_05_pk | 24859700 schedule_line_audit_2014_05_checkpoint_idx | 24859700 schedule_line_audit_2014_05 | 24859700 schedule_line_audit_2014_05_time_fact_idx | 24859700 schedule_line_audit_2014_05_audit_timestamp_idx | 24859700 schedule_line_audit_2014_05_schedule_end_datetime_idx | 24859700 schedule_line_audit_2014_05_time_plan_idx | 24859700 matching_matchingevent_2014_04_device_idx | 24449500 matching_matchingevent_2014_04_start_datetime_idx | 24449500 (100 rows)
pgsql-performance by date: