RE: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4

From: "ldh(at)laurent-hasson(dot)com" <ldh(at)laurent-hasson(dot)com>
To: Ranier Vilela <ranier(dot)vf(at)gmail(dot)com>, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
Cc: Andrew Dunstan <andrew(at)dunslane(dot)net>, Justin Pryzby <pryzby(at)telsasoft(dot)com>, "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: RE: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4
Date: 2021-08-29 16:03:02
Message-ID: MN2PR15MB25605C2D5D70A6EAF99B5F6085CA9@MN2PR15MB2560.namprd15.prod.outlook.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

>Sure, there's no question that message translation will have *some* cost.
>But on my machine it is an incremental tens-of-percent kind of cost,
>and that is the result you're getting as well.  So it's not very clear
>where these factor-of-several-hundred differences are coming from.
>A hypothesis that has not yet come up, may be some defect in the code generation,
>by the previous msvc compiler used, because in all my tests I always use the latest version,
>which has several corrections in the code generation part.

------------------------------------------------------------------------------------------------------------------------

Hello all,

I don't think this reproduces the issue I experience. I saw a difference of around 500x! What you see is 5x, which according to Tom would be expected for an execution path involving exceptions. And NLS should have an impact as well since more work happens. From the numbers you published, I see 10-15% change which again would be expected?

I cannot think of anything that would be specific to me with regards to this scenario given that I have tried it in quite a few environments from plain stock installs. Until one of you is able to reproduce this, you may be chasing other issues.

Is it possible that the client I am using or the way I am creating the test database might affect this scenario? I use DBeaver and use the default settings to create the database:
- default encoding: UTF8
- collate: English_United States.1252
- ctype: English_United States.1252
- default tablespace: pg_default

Settings:
Name Value Unit
allow_system_table_mods off [NULL]
application_name DBeaver 21.1.3 - Main <postgres> [NULL]
archive_cleanup_command [NULL]
archive_command (disabled) [NULL]
archive_mode off [NULL]
archive_timeout 0 s
array_nulls on [NULL]
authentication_timeout 60 s
autovacuum on [NULL]
autovacuum_analyze_scale_factor 0.1 [NULL]
autovacuum_analyze_threshold 50 [NULL]
autovacuum_freeze_max_age 200000000 [NULL]
autovacuum_max_workers 3 [NULL]
autovacuum_multixact_freeze_max_age 400000000 [NULL]
autovacuum_naptime 60 s
autovacuum_vacuum_cost_delay 2 ms
autovacuum_vacuum_cost_limit -1 [NULL]
autovacuum_vacuum_insert_scale_factor 0.2 [NULL]
autovacuum_vacuum_insert_threshold 1000 [NULL]
autovacuum_vacuum_scale_factor 0.2 [NULL]
autovacuum_vacuum_threshold 50 [NULL]
autovacuum_work_mem -1 kB
backend_flush_after 0 8kB
backslash_quote safe_encoding [NULL]
backtrace_functions [NULL]
bgwriter_delay 200 ms
bgwriter_flush_after 0 8kB
bgwriter_lru_maxpages 100 [NULL]
bgwriter_lru_multiplier 2 [NULL]
block_size 8192 [NULL]
bonjour off [NULL]
bonjour_name [NULL]
bytea_output hex [NULL]
check_function_bodies on [NULL]
checkpoint_completion_target 0.5 [NULL]
checkpoint_flush_after 0 8kB
checkpoint_timeout 300 s
checkpoint_warning 30 s
client_encoding UTF8 [NULL]
client_min_messages notice [NULL]
cluster_name [NULL]
commit_delay 0 [NULL]
commit_siblings 5 [NULL]
config_file C:/Program Files/PostgreSQL/13/data/postgresql.conf [NULL]
constraint_exclusion partition [NULL]
cpu_index_tuple_cost 0.005 [NULL]
cpu_operator_cost 0.0025 [NULL]
cpu_tuple_cost 0.01 [NULL]
cursor_tuple_fraction 0.1 [NULL]
data_checksums off [NULL]
data_directory C:/Program Files/PostgreSQL/13/data [NULL]
data_directory_mode 700 [NULL]
data_sync_retry off [NULL]
DateStyle ISO, YMD [NULL]
db_user_namespace off [NULL]
deadlock_timeout 1000 ms
debug_assertions off [NULL]
debug_pretty_print on [NULL]
debug_print_parse off [NULL]
debug_print_plan off [NULL]
debug_print_rewritten off [NULL]
default_statistics_target 100 [NULL]
default_table_access_method heap [NULL]
default_tablespace [NULL]
default_text_search_config pg_catalog.english [NULL]
default_transaction_deferrable off [NULL]
default_transaction_isolation read committed [NULL]
default_transaction_read_only off [NULL]
dynamic_library_path $libdir [NULL]
dynamic_shared_memory_type windows [NULL]
effective_cache_size 524288 8kB
effective_io_concurrency 0 [NULL]
enable_bitmapscan on [NULL]
enable_gathermerge on [NULL]
enable_hashagg on [NULL]
enable_hashjoin on [NULL]
enable_incremental_sort on [NULL]
enable_indexonlyscan on [NULL]
enable_indexscan on [NULL]
enable_material on [NULL]
enable_mergejoin on [NULL]
enable_nestloop on [NULL]
enable_parallel_append on [NULL]
enable_parallel_hash on [NULL]
enable_partition_pruning on [NULL]
enable_partitionwise_aggregate off [NULL]
enable_partitionwise_join off [NULL]
enable_seqscan on [NULL]
enable_sort on [NULL]
enable_tidscan on [NULL]
escape_string_warning on [NULL]
event_source PostgreSQL [NULL]
exit_on_error off [NULL]
external_pid_file [NULL]
extra_float_digits 3 [NULL]
force_parallel_mode off [NULL]
from_collapse_limit 8 [NULL]
fsync on [NULL]
full_page_writes on [NULL]
geqo on [NULL]
geqo_effort 5 [NULL]
geqo_generations 0 [NULL]
geqo_pool_size 0 [NULL]
geqo_seed 0 [NULL]
geqo_selection_bias 2 [NULL]
geqo_threshold 12 [NULL]
gin_fuzzy_search_limit 0 [NULL]
gin_pending_list_limit 4096 kB
hash_mem_multiplier 1 [NULL]
hba_file C:/Program Files/PostgreSQL/13/data/pg_hba.conf [NULL]
hot_standby on [NULL]
hot_standby_feedback off [NULL]
huge_pages try [NULL]
ident_file C:/Program Files/PostgreSQL/13/data/pg_ident.conf [NULL]
idle_in_transaction_session_timeout 0 ms
ignore_checksum_failure off [NULL]
ignore_invalid_pages off [NULL]
ignore_system_indexes off [NULL]
integer_datetimes on [NULL]
IntervalStyle postgres [NULL]
jit off [NULL]
jit_above_cost 100000 [NULL]
jit_debugging_support off [NULL]
jit_dump_bitcode off [NULL]
jit_expressions on [NULL]
jit_inline_above_cost 500000 [NULL]
jit_optimize_above_cost 500000 [NULL]
jit_profiling_support off [NULL]
jit_provider llvmjit [NULL]
jit_tuple_deforming on [NULL]
join_collapse_limit 8 [NULL]
krb_caseins_users off [NULL]
krb_server_keyfile [NULL]
lc_collate English_United States.1252 [NULL]
lc_ctype English_United States.1252 [NULL]
lc_messages English_United States.1252 [NULL]
lc_monetary English_United States.1252 [NULL]
lc_numeric English_United States.1252 [NULL]
lc_time English_United States.1252 [NULL]
listen_addresses * [NULL]
lo_compat_privileges off [NULL]
local_preload_libraries [NULL]
lock_timeout 0 ms
log_autovacuum_min_duration -1 ms
log_checkpoints off [NULL]
log_connections off [NULL]
log_destination stderr [NULL]
log_directory log [NULL]
log_disconnections off [NULL]
log_duration off [NULL]
log_error_verbosity default [NULL]
log_executor_stats off [NULL]
log_file_mode 640 [NULL]
log_filename postgresql-%Y-%m-%d_%H%M%S.log [NULL]
log_hostname off [NULL]
log_line_prefix %m [%p] [NULL]
log_lock_waits off [NULL]
log_min_duration_sample -1 ms
log_min_duration_statement -1 ms
log_min_error_statement error [NULL]
log_min_messages warning [NULL]
log_parameter_max_length -1 B
log_parameter_max_length_on_error 0 B
log_parser_stats off [NULL]
log_planner_stats off [NULL]
log_replication_commands off [NULL]
log_rotation_age 1440 min
log_rotation_size 10240 kB
log_statement none [NULL]
log_statement_sample_rate 1 [NULL]
log_statement_stats off [NULL]
log_temp_files -1 kB
log_timezone US/Eastern [NULL]
log_transaction_sample_rate 0 [NULL]
log_truncate_on_rotation off [NULL]
logging_collector on [NULL]
logical_decoding_work_mem 65536 kB
maintenance_io_concurrency 0 [NULL]
maintenance_work_mem 65536 kB
max_connections 100 [NULL]
max_files_per_process 1000 [NULL]
max_function_args 100 [NULL]
max_identifier_length 63 [NULL]
max_index_keys 32 [NULL]
max_locks_per_transaction 64 [NULL]
max_logical_replication_workers 4 [NULL]
max_parallel_maintenance_workers 2 [NULL]
max_parallel_workers 8 [NULL]
max_parallel_workers_per_gather 2 [NULL]
max_pred_locks_per_page 2 [NULL]
max_pred_locks_per_relation -2 [NULL]
max_pred_locks_per_transaction 64 [NULL]
max_prepared_transactions 0 [NULL]
max_replication_slots 10 [NULL]
max_slot_wal_keep_size -1 MB
max_stack_depth 2048 kB
max_standby_archive_delay 30000 ms
max_standby_streaming_delay 30000 ms
max_sync_workers_per_subscription 2 [NULL]
max_wal_senders 10 [NULL]
max_wal_size 1024 MB
max_worker_processes 8 [NULL]
min_parallel_index_scan_size 64 8kB
min_parallel_table_scan_size 1024 8kB
min_wal_size 80 MB
old_snapshot_threshold -1 min
operator_precedence_warning off [NULL]
parallel_leader_participation on [NULL]
parallel_setup_cost 1000 [NULL]
parallel_tuple_cost 0.1 [NULL]
password_encryption scram-sha-256 [NULL]
plan_cache_mode auto [NULL]
port 5433 [NULL]
post_auth_delay 0 s
pre_auth_delay 0 s
primary_conninfo [NULL]
primary_slot_name [NULL]
promote_trigger_file [NULL]
quote_all_identifiers off [NULL]
random_page_cost 4 [NULL]
recovery_end_command [NULL]
recovery_min_apply_delay 0 ms
recovery_target [NULL]
recovery_target_action pause [NULL]
recovery_target_inclusive on [NULL]
recovery_target_lsn [NULL]
recovery_target_name [NULL]
recovery_target_time [NULL]
recovery_target_timeline latest [NULL]
recovery_target_xid [NULL]
restart_after_crash on [NULL]
restore_command [NULL]
row_security on [NULL]
search_path $user, public [NULL]
segment_size 131072 8kB
seq_page_cost 1 [NULL]
server_encoding UTF8 [NULL]
server_version 13.4 [NULL]
server_version_num 130004 [NULL]
session_preload_libraries [NULL]
session_replication_role origin [NULL]
shared_buffers 16384 8kB
shared_memory_type windows [NULL]
shared_preload_libraries [NULL]
ssl off [NULL]
ssl_ca_file [NULL]
ssl_cert_file server.crt [NULL]
ssl_ciphers HIGH:MEDIUM:+3DES:!aNULL [NULL]
ssl_crl_file [NULL]
ssl_dh_params_file [NULL]
ssl_ecdh_curve prime256v1 [NULL]
ssl_key_file server.key [NULL]
ssl_library OpenSSL [NULL]
ssl_max_protocol_version [NULL]
ssl_min_protocol_version TLSv1.2 [NULL]
ssl_passphrase_command [NULL]
ssl_passphrase_command_supports_reload off [NULL]
ssl_prefer_server_ciphers on [NULL]
standard_conforming_strings on [NULL]
statement_timeout 0 ms
stats_temp_directory pg_stat_tmp [NULL]
superuser_reserved_connections 3 [NULL]
synchronize_seqscans on [NULL]
synchronous_commit on [NULL]
synchronous_standby_names [NULL]
syslog_facility none [NULL]
syslog_ident postgres [NULL]
syslog_sequence_numbers on [NULL]
syslog_split_messages on [NULL]
tcp_keepalives_count 0 [NULL]
tcp_keepalives_idle -1 s
tcp_keepalives_interval -1 s
tcp_user_timeout 0 ms
temp_buffers 1024 8kB
temp_file_limit -1 kB
temp_tablespaces [NULL]
TimeZone America/New_York [NULL]
timezone_abbreviations Default [NULL]
trace_notify off [NULL]
trace_recovery_messages log [NULL]
trace_sort off [NULL]
track_activities on [NULL]
track_activity_query_size 1024 B
track_commit_timestamp off [NULL]
track_counts on [NULL]
track_functions none [NULL]
track_io_timing off [NULL]
transaction_deferrable off [NULL]
transaction_isolation read committed [NULL]
transaction_read_only off [NULL]
transform_null_equals off [NULL]
unix_socket_directories [NULL]
unix_socket_group [NULL]
unix_socket_permissions 777 [NULL]
update_process_title off [NULL]
vacuum_cleanup_index_scale_factor 0.1 [NULL]
vacuum_cost_delay 0 ms
vacuum_cost_limit 200 [NULL]
vacuum_cost_page_dirty 20 [NULL]
vacuum_cost_page_hit 1 [NULL]
vacuum_cost_page_miss 10 [NULL]
vacuum_defer_cleanup_age 0 [NULL]
vacuum_freeze_min_age 50000000 [NULL]
vacuum_freeze_table_age 150000000 [NULL]
vacuum_multixact_freeze_min_age 5000000 [NULL]
vacuum_multixact_freeze_table_age 150000000 [NULL]
wal_block_size 8192 [NULL]
wal_buffers 512 8kB
wal_compression off [NULL]
wal_consistency_checking [NULL]
wal_init_zero on [NULL]
wal_keep_size 0 MB
wal_level replica [NULL]
wal_log_hints off [NULL]
wal_receiver_create_temp_slot off [NULL]
wal_receiver_status_interval 10 s
wal_receiver_timeout 60000 ms
wal_recycle on [NULL]
wal_retrieve_retry_interval 5000 ms
wal_segment_size 16777216 B
wal_sender_timeout 60000 ms
wal_skip_threshold 2048 kB
wal_sync_method open_datasync [NULL]
wal_writer_delay 200 ms
wal_writer_flush_after 128 8kB
work_mem 4096 kB
xmlbinary base64 [NULL]
xmloption content [NULL]
zero_damaged_pages off [NULL]

Thank you,
Laurent.

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2021-08-29 16:19:08 Re: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4
Previous Message Ranier Vilela 2021-08-29 14:00:44 Re: Big Performance drop of Exceptions in UDFs between V11.2 and 13.4