Post 9nnVS3Rsmvpg3HiRcG by sjw@patch.cx
(DIR) More posts by sjw@patch.cx
(DIR) Post #9nnMPls0H80zMklnUG by sjw@patch.cx
2019-10-10T21:37:26.227085Z
1 likes, 1 repeats
@rin @lanodan Halp! My server is dying. Postgres is eating all my cpu really bad. Postgres logs are full of this:STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((o1."data")->'likes' ? ($2)) AND (not (a0."actor" = ANY($3))) AND (not (a0."recipients" && $4)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $5)) AND (not (split_part(a0."actor", '/', 3) = ANY($6))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($7))) AND (NOT (a0."actor" = ANY($8))) AND (not(o1."data"->>'type' = 'Answer')) ORDER BY a0."id" desc nulls last LIMIT $9Is an index missing or something? I'm running the latest develop.
(DIR) Post #9nnO0OUMGlWjWDjl6e by sjw@patch.cx
2019-10-10T21:55:17.202710Z
0 likes, 0 repeats
cc @lain @feld @minibikini @kPherox :NotLikeThis:
(DIR) Post #9nnOAO5ebc9vB8wmg4 by feld@bikeshed.party
2019-10-10T21:57:04.530890Z
1 likes, 0 repeats
@sjw @lanodan @rin before we blame a query/index:how much RAM does your database server have, and how big is your database? It's possible there's a pileup due to lack of memory and not just a missing index causing full table scans.
(DIR) Post #9nnOl3Jknh0xT61dj6 by sjw@patch.cx
2019-10-10T22:03:39.604406Z
0 likes, 0 repeats
@feld @lanodan @rin SELECT pg_size_pretty( pg_database_size('pleroma_dev') ); pg_size_pretty ---------------- 43 GB(1 row)Here’s my postgres config. It should have around 3GB of RAM # -----------------------------# PostgreSQL configuration file# -----------------------------## This file consists of lines of the form:## name = value## (The "=" is optional.) Whitespace may be used. Comments are introduced with# "#" anywhere on a line. The complete list of parameter names and allowed# values can be found in the PostgreSQL documentation.## The commented-out settings shown in this file represent the default values.# Re-commenting a setting is NOT sufficient to revert it to the default value;# you need to reload the server.## This file is read on server startup and when the server receives a SIGHUP# signal. If you edit the file on a running system, you have to SIGHUP the# server for the changes to take effect, run "pg_ctl reload", or execute# "SELECT pg_reload_conf()". Some parameters, which are marked below,# require a server shutdown and restart to take effect.## Any parameter can also be given as a command-line option to the server, e.g.,# "postgres -c log_connections=on". Some parameters can be changed at run time# with the "SET" SQL command.## Memory units: kB = kilobytes Time units: ms = milliseconds# MB = megabytes s = seconds# GB = gigabytes min = minutes# TB = terabytes h = hours# d = days#------------------------------------------------------------------------------# FILE LOCATIONS#------------------------------------------------------------------------------# The default values of these variables are driven from the -D command-line# option or PGDATA environment variable, represented here as ConfigDir.#data_directory = 'ConfigDir' # use data in another directory # (change requires restart)#hba_file = 'ConfigDir/pg_hba.conf' # host-based authentication file # (change requires restart)#ident_file = 'ConfigDir/pg_ident.conf' # ident configuration file # (change requires restart)# If external_pid_file is not explicitly set, no extra PID file is written.#external_pid_file = '' # write an extra PID file # (change requires restart)#------------------------------------------------------------------------------# CONNECTIONS AND AUTHENTICATION#------------------------------------------------------------------------------# - Connection Settings -#listen_addresses = 'localhost' # what IP address(es) to listen on; # comma-separated list of addresses; # defaults to 'localhost'; use '*' for all # (change requires restart)#port = 5432 # (change requires restart)max_connections = 70 # (change requires restart)#superuser_reserved_connections = 3 # (change requires restart)#unix_socket_directories = '/run/postgresql' # comma-separated list of directories # (change requires restart)#unix_socket_group = '' # (change requires restart)#unix_socket_permissions = 0777 # begin with 0 to use octal notation # (change requires restart)#bonjour = off # advertise server via Bonjour # (change requires restart)#bonjour_name = '' # defaults to the computer name # (change requires restart)# - TCP Keepalives -# see "man 7 tcp" for details#tcp_keepalives_idle = 0 # TCP_KEEPIDLE, in seconds; # 0 selects the system default#tcp_keepalives_interval = 0 # TCP_KEEPINTVL, in seconds; # 0 selects the system default#tcp_keepalives_count = 0 # TCP_KEEPCNT; # 0 selects the system default# - Authentication -#authentication_timeout = 1min # 1s-600s#password_encryption = md5 # md5 or scram-sha-256#db_user_namespace = off# GSSAPI using Kerberos#krb_server_keyfile = ''#krb_caseins_users = off# - SSL -#ssl = off#ssl_ca_file = ''#ssl_cert_file = 'server.crt'#ssl_crl_file = ''#ssl_key_file = 'server.key'#ssl_ciphers = 'HIGH:MEDIUM:+3DES:!aNULL' # allowed SSL ciphers#ssl_prefer_server_ciphers = on#ssl_ecdh_curve = 'prime256v1'#ssl_dh_params_file = ''#ssl_passphrase_command = ''#ssl_passphrase_command_supports_reload = off#------------------------------------------------------------------------------# RESOURCE USAGE (except WAL)#------------------------------------------------------------------------------# - Memory -shared_buffers = 628MB # min 128kB # (change requires restart)#huge_pages = try # on, off, or try # (change requires restart)#temp_buffers = 8MB # min 800kB#max_prepared_transactions = 0 # zero disables the feature # (change requires restart)# Caution: it is not advisable to set max_prepared_transactions nonzero unless# you actively intend to use prepared transactions.work_mem = 21333kB # min 64kBmaintenance_work_mem = 160MB # min 1MB#autovacuum_work_mem = -1 # min 1MB, or -1 to use maintenance_work_mem#max_stack_depth = 2MB # min 100kBdynamic_shared_memory_type = posix # the default is the first option # supported by the operating system: # posix # sysv # windows # mmap # use none to disable dynamic shared memory # (change requires restart)# - Disk -#temp_file_limit = -1 # limits per-process temp file space # in kB, or -1 for no limit# - Kernel Resources -#max_files_per_process = 1000 # min 25 # (change requires restart)# - Cost-Based Vacuum Delay -#vacuum_cost_delay = 0 # 0-100 milliseconds#vacuum_cost_page_hit = 1 # 0-10000 credits#vacuum_cost_page_miss = 10 # 0-10000 credits#vacuum_cost_page_dirty = 20 # 0-10000 creditsvacuum_cost_limit = 650 # 1-10000 credits# - Background Writer -#bgwriter_delay = 200ms # 10-10000ms between rounds#bgwriter_lru_maxpages = 100 # max buffers written/round, 0 disables#bgwriter_lru_multiplier = 2.0 # 0-10.0 multiplier on buffers scanned/round#bgwriter_flush_after = 512kB # measured in pages, 0 disables# - Asynchronous Behavior -effective_io_concurrency = 115 # 1-1000; 0 disables prefetchingmax_worker_processes = 2 # (change requires restart)max_parallel_maintenance_workers = 1 # taken from max_parallel_workersmax_parallel_workers_per_gather = 1 # taken from max_parallel_workers#parallel_leader_participation = onmax_parallel_workers = 2 # maximum number of max_worker_processes that # can be used in parallel operations#old_snapshot_threshold = -1 # 1min-60d; -1 disables; 0 is immediate # (change requires restart)#backend_flush_after = 0 # measured in pages, 0 disables#------------------------------------------------------------------------------# WRITE-AHEAD LOG#------------------------------------------------------------------------------# - Settings -#wal_level = replica # minimal, replica, or logical # (change requires restart)#fsync = on # flush data to disk for crash safety # (turning this off can cause # unrecoverable data corruption)#synchronous_commit = on # synchronization level; # off, local, remote_write, remote_apply, or on#wal_sync_method = fsync # the default is the first option # supported by the operating system: # open_datasync # fdatasync (default on Linux) # fsync # fsync_writethrough # open_sync#full_page_writes = on # recover from partial page writes#wal_compression = off # enable compression of full-page writes#wal_log_hints = off # also do full page writes of non-critical updates # (change requires restart)wal_buffers = 16MB # min 32kB, -1 sets based on shared_buffers # (change requires restart)#wal_writer_delay = 200ms # 1-10000 milliseconds#wal_writer_flush_after = 1MB # measured in pages, 0 disables#commit_delay = 0 # range 0-100000, in microseconds#commit_siblings = 5 # range 1-1000# - Checkpoints -#checkpoint_timeout = 5min # range 30s-1dmax_wal_size = 1GBmin_wal_size = 2GBcheckpoint_completion_target = 0.9 # checkpoint target duration, 0.0 - 1.0#checkpoint_flush_after = 256kB # measured in pages, 0 disables#checkpoint_warning = 30s # 0 disables# - Archiving -#archive_mode = off # enables archiving; off, on, or always # (change requires restart)#archive_command = '' # command to use to archive a logfile segment # placeholders: %p = path of file to archive # %f = file name only # e.g. 'test ! -f /mnt/server/archivedir/%f && cp %p /mnt/server/archivedir/%f'#archive_timeout = 0 # force a logfile segment switch after this # number of seconds; 0 disables#------------------------------------------------------------------------------# REPLICATION#------------------------------------------------------------------------------# - Sending Servers -# Set these on the master and on any standby that will send replication data.#max_wal_senders = 10 # max number of walsender processes # (change requires restart)#wal_keep_segments = 0 # in logfile segments; 0 disables#wal_sender_timeout = 60s # in milliseconds; 0 disables#max_replication_slots = 10 # max number of replication slots # (change requires restart)#track_commit_timestamp = off # collect timestamp of transaction commit # (change requires restart)# - Master Server -# These settings are ignored on a standby server.#synchronous_standby_names = '' # standby servers that provide sync rep # method to choose sync standbys, number of sync standbys, # and comma-separated list of application_name # from standby(s); '*' = all#vacuum_defer_cleanup_age = 0 # number of xacts by which cleanup is delayed# - Standby Servers -# These settings are ignored on a master server.#hot_standby = on # "off" disallows queries during recovery # (change requires restart)#max_standby_archive_delay = 30s # max delay before canceling queries # when reading WAL from archive; # -1 allows indefinite delay#max_standby_streaming_delay = 30s # max delay before canceling queries # when reading streaming WAL; # -1 allows indefinite delay#wal_receiver_status_interval = 10s # send replies at least this often # 0 disables#hot_standby_feedback = off # send info from standby to prevent # query conflicts#wal_receiver_timeout = 60s # time that receiver waits for # communication from master # in milliseconds; 0 disables#wal_retrieve_retry_interval = 5s # time to wait before retrying to # retrieve WAL after a failed attempt# - Subscribers -# These settings are ignored on a publisher.#max_logical_replication_workers = 4 # taken from max_worker_processes # (change requires restart)#max_sync_workers_per_subscription = 2 # taken from max_logical_replication_workers#------------------------------------------------------------------------------# QUERY TUNING#------------------------------------------------------------------------------# - Planner Method Configuration -#enable_bitmapscan = on#enable_hashagg = on#enable_hashjoin = on#enable_indexscan = on#enable_indexonlyscan = on#enable_material = on#enable_mergejoin = on#enable_nestloop = on#enable_parallel_append = on#enable_seqscan = on#enable_sort = on#enable_tidscan = on#enable_partitionwise_join = off#enable_partitionwise_aggregate = off#enable_parallel_hash = on#enable_partition_pruning = on# - Planner Cost Constants -#seq_page_cost = 1.0 # measured on an arbitrary scale#random_page_cost = 4.0 # same scale as aboverandom_page_cost = 1.1#cpu_tuple_cost = 0.01 # same scale as above#cpu_index_tuple_cost = 0.005 # same scale as above#cpu_operator_cost = 0.0025 # same scale as above#parallel_tuple_cost = 0.1 # same scale as above#parallel_setup_cost = 1000.0 # same scale as above#jit_above_cost = 100000 # perform JIT compilation if available # and query more expensive than this; # -1 disables#jit_inline_above_cost = 500000 # inline small functions if query is # more expensive than this; -1 disables#jit_optimize_above_cost = 500000 # use expensive JIT optimizations if # query is more expensive than this; # -1 disables#min_parallel_table_scan_size = 8MB#min_parallel_index_scan_size = 512kBeffective_cache_size = 1875MB# - Genetic Query Optimizer -#geqo = on#geqo_threshold = 12#geqo_effort = 5 # range 1-10#geqo_pool_size = 0 # selects default based on effort#geqo_generations = 0 # selects default based on effort#geqo_selection_bias = 2.0 # range 1.5-2.0#geqo_seed = 0.0 # range 0.0-1.0# - Other Planner Options -#default_statistics_target = 100 # range 1-10000#constraint_exclusion = partition # on, off, or partition#cursor_tuple_fraction = 0.1 # range 0.0-1.0#from_collapse_limit = 8#join_collapse_limit = 8 # 1 disables collapsing of explicit # JOIN clauses#force_parallel_mode = offjit = on # allow JIT compilation#------------------------------------------------------------------------------# REPORTING AND LOGGING#------------------------------------------------------------------------------# - Where to Log -#log_destination = 'stderr' # Valid values are combinations of # stderr, csvlog, syslog, and eventlog, # depending on platform. csvlog # requires logging_collector to be on.# This is used when logging to stderr:#logging_collector = off # Enable capturing of stderr and csvlog # into log files. Required to be on for # csvlogs. # (change requires restart)# These are only used if logging_collector is on:#log_directory = 'log' # directory where log files are written, # can be absolute or relative to PGDATA#log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' # log file name pattern, # can include strftime() escapes#log_file_mode = 0600 # creation mode for log files, # begin with 0 to use octal notation#log_truncate_on_rotation = off # If on, an existing log file with the # same name as the new log file will be # truncated rather than appended to. # But such truncation only occurs on # time-driven rotation, not on restarts # or size-driven rotation. Default is # off, meaning append to existing files # in all cases.#log_rotation_age = 1d # Automatic rotation of logfiles will # happen after that time. 0 disables.#log_rotation_size = 10MB # Automatic rotation of logfiles will # happen after that much log output. # 0 disables.# These are relevant when logging to syslog:#syslog_facility = 'LOCAL0'#syslog_ident = 'postgres'#syslog_sequence_numbers = on#syslog_split_messages = on# This is only relevant when logging to eventlog (win32):# (change requires restart)#event_source = 'PostgreSQL'# - When to Log -#log_min_messages = warning # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # info # notice # warning # error # log # fatal # panic#log_min_error_statement = error # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # info # notice # warning # error # log # fatal # panic (effectively off)#log_min_duration_statement = -1 # -1 is disabled, 0 logs all statements # and their durations, > 0 logs only # statements running at least this number # of milliseconds# - What to Log -#debug_print_parse = off#debug_print_rewritten = off#debug_print_plan = off#debug_pretty_print = on#log_checkpoints = off#log_connections = off#log_disconnections = off#log_duration = off#log_error_verbosity = default # terse, default, or verbose messages#log_hostname = off#log_line_prefix = '%m [%p] ' # special values: # %a = application name # %u = user name # %d = database name # %r = remote host and port # %h = remote host # %p = process ID # %t = timestamp without milliseconds # %m = timestamp with milliseconds # %n = timestamp with milliseconds (as a Unix epoch) # %i = command tag # %e = SQL state # %c = session ID # %l = session line number # %s = session start timestamp # %v = virtual transaction ID # %x = transaction ID (0 if none) # %q = stop here in non-session # processes # %% = '%' # e.g. '<%u%%%d> '#log_lock_waits = off # log lock waits >= deadlock_timeout#log_statement = 'none' # none, ddl, mod, all#log_replication_commands = off#log_temp_files = -1 # log temporary files equal or larger # than the specified size in kilobytes; # -1 disables, 0 logs all temp fileslog_timezone = 'America/Los_Angeles'#------------------------------------------------------------------------------# PROCESS TITLE#------------------------------------------------------------------------------#cluster_name = '' # added to process titles if nonempty # (change requires restart)#update_process_title = on#------------------------------------------------------------------------------# STATISTICS#------------------------------------------------------------------------------# - Query and Index Statistics Collector -#track_activities = on#track_counts = on#track_io_timing = off#track_functions = none # none, pl, all#track_activity_query_size = 1024 # (change requires restart)#stats_temp_directory = 'pg_stat_tmp'# - Monitoring -#log_parser_stats = off#log_planner_stats = off#log_executor_stats = off#log_statement_stats = off#------------------------------------------------------------------------------# AUTOVACUUM#------------------------------------------------------------------------------#autovacuum = on # Enable autovacuum subprocess? 'on' # requires track_counts to also be on.#log_autovacuum_min_duration = -1 # -1 disables, 0 logs all actions and # their durations, > 0 logs only # actions running at least this number # of milliseconds.#autovacuum_max_workers = 3 # max number of autovacuum subprocesses # (change requires restart)#autovacuum_naptime = 1min # time between autovacuum runs#autovacuum_vacuum_threshold = 50 # min number of row updates before # vacuum#autovacuum_analyze_threshold = 50 # min number of row updates before # analyzeautovacuum_vacuum_scale_factor = 0.02 # fraction of table size before vacuumautovacuum_analyze_scale_factor = 0.04 # fraction of table size before analyze#autovacuum_freeze_max_age = 200000000 # maximum XID age before forced vacuum # (change requires restart)#autovacuum_multixact_freeze_max_age = 400000000 # maximum multixact age # before forced vacuum # (change requires restart)#autovacuum_vacuum_cost_delay = 20ms # default vacuum cost delay for # autovacuum, in milliseconds; # -1 means use vacuum_cost_delay#autovacuum_vacuum_cost_limit = -1 # default vacuum cost limit for # autovacuum, -1 means use # vacuum_cost_limit#------------------------------------------------------------------------------# CLIENT CONNECTION DEFAULTS#------------------------------------------------------------------------------# - Statement Behavior -#client_min_messages = notice # values in order of decreasing detail: # debug5 # debug4 # debug3 # debug2 # debug1 # log # notice # warning # error#search_path = '"$user", public' # schema names#row_security = on#default_tablespace = '' # a tablespace name, '' uses the default#temp_tablespaces = '' # a list of tablespace names, '' uses # only default tablespace#check_function_bodies = on#default_transaction_isolation = 'read committed'#default_transaction_read_only = off#default_transaction_deferrable = off#session_replication_role = 'origin'#statement_timeout = 0 # in milliseconds, 0 is disabled#lock_timeout = 0 # in milliseconds, 0 is disabled#idle_in_transaction_session_timeout = 0 # in milliseconds, 0 is disabled#vacuum_freeze_min_age = 50000000#vacuum_freeze_table_age = 150000000#vacuum_multixact_freeze_min_age = 5000000#vacuum_multixact_freeze_table_age = 150000000#vacuum_cleanup_index_scale_factor = 0.1 # fraction of total number of tuples # before index cleanup, 0 always performs # index cleanup#bytea_output = 'hex' # hex, escape#xmlbinary = 'base64'#xmloption = 'content'#gin_fuzzy_search_limit = 0#gin_pending_list_limit = 4MB# - Locale and Formatting -datestyle = 'iso, mdy'#intervalstyle = 'postgres'timezone = 'America/Los_Angeles'#timezone_abbreviations = 'Default' # Select the set of available time zone # abbreviations. Currently, there are # Default # Australia (historical usage) # India # You can create your own file in # share/timezonesets/.#extra_float_digits = 0 # min -15, max 3#client_encoding = sql_ascii # actually, defaults to database # encoding# These settings are initialized by initdb, but they can be changed.lc_messages = 'en_US.UTF-8' # locale for system error message # stringslc_monetary = 'en_US.UTF-8' # locale for monetary formattinglc_numeric = 'en_US.UTF-8' # locale for number formattinglc_time = 'en_US.UTF-8' # locale for time formatting# default configuration for text searchdefault_text_search_config = 'pg_catalog.english'# - Shared Library Preloading -#shared_preload_libraries = '' # (change requires restart)#local_preload_libraries = ''#session_preload_libraries = ''#jit_provider = 'llvmjit' # JIT library to use# - Other Defaults -#dynamic_library_path = '$libdir'#------------------------------------------------------------------------------# LOCK MANAGEMENT#------------------------------------------------------------------------------#deadlock_timeout = 1s#max_locks_per_transaction = 64 # min 10 # (change requires restart)#max_pred_locks_per_transaction = 64 # min 10 # (change requires restart)#max_pred_locks_per_relation = -2 # negative values mean # (max_pred_locks_per_transaction # / -max_pred_locks_per_relation) - 1#max_pred_locks_per_page = 2 # min 0#------------------------------------------------------------------------------# VERSION AND PLATFORM COMPATIBILITY#------------------------------------------------------------------------------# - Previous PostgreSQL Versions -#array_nulls = on#backslash_quote = safe_encoding # on, off, or safe_encoding#default_with_oids = off#escape_string_warning = on#lo_compat_privileges = off#operator_precedence_warning = off#quote_all_identifiers = off#standard_conforming_strings = on#synchronize_seqscans = on# - Other Platforms and Clients -#transform_null_equals = off#------------------------------------------------------------------------------# ERROR HANDLING#------------------------------------------------------------------------------#exit_on_error = off # terminate session on any error?#restart_after_crash = on # reinitialize after backend crash?#data_sync_retry = off # retry or panic on failure to fsync # data? # (change requires restart)#------------------------------------------------------------------------------# CONFIG FILE INCLUDES#------------------------------------------------------------------------------# These options allow settings to be loaded from files other than the# default postgresql.conf.#include_dir = '' # include files ending in '.conf' from # a directory, e.g., 'conf.d'#include_if_exists = '' # include file only if it exists#include = '' # include file#------------------------------------------------------------------------------# CUSTOMIZED OPTIONS#------------------------------------------------------------------------------# Add settings for extensions here
(DIR) Post #9nnVS3Rsmvpg3HiRcG by sjw@patch.cx
2019-10-10T23:18:41.669875Z
0 likes, 0 repeats
@feld @lanodan @rin Any ideas? Anything that you see should be changed?
(DIR) Post #9nnVfjzBwmLLk9p1Ga by feld@bikeshed.party
2019-10-10T23:21:09.318940Z
1 likes, 0 repeats
@sjw @lanodan @rin I'm not an expert on what to expect for these queries, just have experience with general database tuning. So I'm like a DBA-lite haha
(DIR) Post #9nnW2w5z5eD9xe3kUy by sjw@patch.cx
2019-10-10T23:25:22.517518Z
0 likes, 0 repeats
@feld @lanodan @rin Same here. Though, it was working fine until about a week ago. It could probably be tuned a little better but it shouldn't be this bad. The only thing I can think of is that an index is missing or bad. I'm no database expert tho.
(DIR) Post #9nneqW6CASPWVLLWoS by lanodan@queer.hacktivis.me
2019-10-11T01:03:54.759776Z
1 likes, 0 repeats
@sjw @feld @rin Well, not much on DBs either but what does it gives you when running the query with *dalek sounds* EXPLAIN before it?
(DIR) Post #9nnfFwaqnbMbunoGOm by feld@bikeshed.party
2019-10-11T01:08:33.479802Z
0 likes, 0 repeats
@lanodan @sjw @rin problem is that without values for all those variables I don't think the EXPLAIN will execute properly
(DIR) Post #9nniP6EubVQIIibb6W by saper@word.builders
2019-10-11T01:43:16.361317Z
2 likes, 0 repeats
@feld @lanodan @rin @sjw You can try to something like this (of course make sure to include full query and all values):pleroma_dev=# prepare test as (select a0."id" from "activities" as a0 limit $1);PREPAREpleroma_dev=# explain analyze execute test(10); QUERY PLAN --------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.00..1.84 rows=10 width=16) (actual time=50.352..50.464 rows=10 loops=1) -> Seq Scan on activities a0 (cost=0.00..157620.52 rows=854952 width=16) (actual time=50.347..50.429 rows=10 loops=1) Planning Time: 330.584 ms Execution Time: 50.546 ms(4 rows)Please submit both the query and a plan to https://explain.depesz.com/ - do not obsfuscate - you might only want to mask some actual valueshttps://explain.depesz.com/s/a31B
(DIR) Post #9nnnkI4GJzqcpzY2L2 by sjw@patch.cx
2019-10-11T02:43:42.464203Z
0 likes, 0 repeats
@saper @feld @lanodan @rin Like this?https://explain.depesz.com/s/a8wepleroma_dev=# prepare test as (select a0."id" from "activities" as a0 limit $1);PREPAREpleroma_dev=# explain analyze execute test(10); QUERY PLAN -------------------------------------------------------------------------------------------------------------------------------------------------------- Limit (cost=0.56..0.76 rows=10 width=16) (actual time=1.217..1.879 rows=10 loops=1) -> Index Only Scan using activities_pkey on activities a0 (cost=0.56..461760.93 rows=23933980 width=16) (actual time=1.215..1.886 rows=10 loops=1) Heap Fetches: 0 Planning Time: 0.208 ms Execution Time: 1.911 ms(5 rows)
(DIR) Post #9nno2hL36WEoQTB3Pk by saper@word.builders
2019-10-11T02:45:17.399448Z
0 likes, 0 repeats
@sjw @feld @lanodan @rin did you paste all of above? (query + dashes + the plan)
(DIR) Post #9nno2hwGs80oHuamQq by sjw@patch.cx
2019-10-11T02:47:01.294868Z
0 likes, 0 repeats
@saper @feld @lanodan @rin Nope, sorry, I fucked up.Here is everything in the code block.https://explain.depesz.com/s/D6MW
(DIR) Post #9nnoEMLOzD78mvu2qG by saper@word.builders
2019-10-11T02:48:31.453799Z
1 likes, 0 repeats
@sjw @feld @lanodan @rin no worries we are all learning here, looks good. Now the challenge will be to copy the values from the Pleroma logfile in a way that Postgres accepts them...
(DIR) Post #9nnoJapkXfu9Asar7w by sjw@patch.cx
2019-10-11T02:50:05.827083Z
0 likes, 0 repeats
@saper @feld @lanodan @rin Would you like my logs? There shouldn't be anything sensitive in there.
(DIR) Post #9nnpudU7kQTs48hnVI by saper@word.builders
2019-10-11T02:52:27.710235Z
0 likes, 0 repeats
@sjw @feld @lanodan @rin Just the line with the values that should follow the query SELECT t0."id", t0."user_id", t0."context" FROM "thread_mutes" AS t0 WHERE (t0."user_id" = $1) AND (t0."context" = $2) [<<0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 23, 31>>, "https://patch.cx/contexts/3e340bed-dcf4-4d80-be79-a43256edc579"](that part in [brackets])
(DIR) Post #9nnpufiNSP4QyvOCzw by sjw@patch.cx
2019-10-11T03:07:56.808795Z
0 likes, 0 repeats
@saper @feld @lanodan @rin All of this?Oct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.782 PDT [190660] LOG: could not send data to client: Broken pipeOct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.783 PDT [190660] FATAL: connection to client lostOct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.835 PDT [190894] ERROR: canceling statement due to user requestOct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.835 PDT [190894] STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((o1."data")->'likes' ? ($2)) AND (not (a0."actor" = ANY($3))) AND (not (a0."recipients" && $4)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $5)) AND (not (split_part(a0."actor", '/', 3) = ANY($6))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($7))) AND (NOT (a0."actor" = ANY($8))) AND (not(o1."data"->>'type' = 'Answer')) ORDER BY a0."id" desc nulls last LIMIT $9Oct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.835 PDT [190894] LOG: could not send data to client: Broken pipeOct 10 20:00:34 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:34.835 PDT [190894] FATAL: connection to client lostOct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.276 PDT [191419] ERROR: canceling statement due to user requestOct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.276 PDT [191419] STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."id" > $1) AND (a0."data"->>'type' = $2) AND ((o1."data")->'likes' ? ($3)) AND (not (a0."actor" = ANY($4))) AND (not (a0."recipients" && $5)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $6)) AND (not (split_part(a0."actor", '/', 3) = ANY($7))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($8))) AND (NOT (a0."actor" = ANY($9))) AND (not(o1."data"->>'type' = 'Answer')) AND (a0."id" > $10) ORDER BY a0."id" desc nulls last LIMIT $11Oct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.279 PDT [191442] FATAL: terminating connection due to administrator commandOct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.279 PDT [191442] STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."id" > $1) AND (a0."data"->>'type' = $2) AND ((o1."data")->'likes' ? ($3)) AND (not (a0."actor" = ANY($4))) AND (not (a0."recipients" && $5)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $6)) AND (not (split_part(a0."actor", '/', 3) = ANY($7))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($8))) AND (NOT (a0."actor" = ANY($9))) AND (not(o1."data"->>'type' = 'Answer')) AND (a0."id" > $10) ORDER BY a0."id" desc nulls last LIMIT $11Oct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.437 PDT [93046] LOG: background worker "parallel worker" (PID 191442) exited with exit code 1Oct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.437 PDT [191419] LOG: could not send data to client: Broken pipeOct 10 20:00:36 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:36.437 PDT [191419] FATAL: connection to client lostOct 10 20:00:46 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:46.396 PDT [190620] ERROR: canceling statement due to user requestOct 10 20:00:46 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:46.396 PDT [190620] STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((o1."data")->'likes' ? ($2)) AND (not (a0."actor" = ANY($3))) AND (not (a0."recipients" && $4)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $5)) AND (not (split_part(a0."actor", '/', 3) = ANY($6))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($7))) AND (NOT (a0."actor" = ANY($8))) AND (not(o1."data"->>'type' = 'Answer')) ORDER BY a0."id" desc nulls last LIMIT $9Oct 10 20:00:46 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:46.397 PDT [190620] LOG: could not send data to client: Broken pipeOct 10 20:00:46 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:46.397 PDT [190620] FATAL: connection to client lostOct 10 20:00:50 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:50.210 PDT [190650] ERROR: canceling statement due to user requestOct 10 20:00:50 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:50.210 PDT [190650] STATEMENT: SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((o1."data")->'likes' ? ($2)) AND (not (a0."actor" = ANY($3))) AND (not (a0."recipients" && $4)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $5)) AND (not (split_part(a0."actor", '/', 3) = ANY($6))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($7))) AND (NOT (a0."actor" = ANY($8))) AND (not(o1."data"->>'type' = 'Answer')) ORDER BY a0."id" desc nulls last LIMIT $9Oct 10 20:00:50 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:50.210 PDT [190650] LOG: could not send data to client: Broken pipeOct 10 20:00:50 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:50.210 PDT [190650] FATAL: connection to client lostOct 10 20:00:51 neckbeard.xyz postgres[93046]: 2019-10-10 20:00:51.650 PDT [190888] ERROR: canceling statement due to user request
(DIR) Post #9nnqEz9Wtfrj3imAc4 by sjw@patch.cx
2019-10-11T03:11:39.893507Z
0 likes, 0 repeats
@lanodan @feld @rin Not really sure what to put for the variablespleroma_dev=# EXPLAIN SELECT a0."id", a0."data", a0."local", a0."actor", a0."recipients", a0."inserted_at", a0."updated_at", o1."id", o1."data", o1."inserted_at", o1."updated_at" FROM "activities" AS a0 INNER JOIN "objects" AS o1 ON (o1."data"->>'id') = COALESCE(a0."data"->'object'->>'id', a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((o1."data")->'likes' ? ($2)) AND (not (a0."actor" = ANY($3))) AND (not (a0."recipients" && $4)) AND (not (a0."data"->>'type' = 'Announce' and a0."data"->'to' ?| $5)) AND (not (split_part(a0."actor", '/', 3) = ANY($6))) AND (not (split_part(o1."data"->>'actor', '/', 3) = ANY($7))) AND (NOT (a0."actor" = ANY($8))) AND (not(o1."data"->>'type' = 'Answer')) ORDER BY a0."id" desc nulls last LIMIT $9pleroma_dev-# ;ERROR: there is no parameter $1LINE 1: ...a0."data"->>'object') WHERE (a0."data"->>'type' = $1) AND ((...
(DIR) Post #9nnqT1v7P6s3hFjSZk by saper@word.builders
2019-10-11T03:09:55.277843Z
1 likes, 0 repeats
@sjw @feld @lanodan @rin uh oh, seems your pleroma does not log values sent to the queries... also it is obvious from the log that someone was trying to shut down Postgres in the meantime
(DIR) Post #9nnqT2DCJtKgbKBtku by sjw@patch.cx
2019-10-11T03:14:11.564222Z
0 likes, 0 repeats
@saper @feld @lanodan @rin Oh, pleroma logs 🤦Oct 10 20:12:31 neckbeard.xyz mix[93057]: ** (exit) an exception was raised:Oct 10 20:12:31 neckbeard.xyz mix[93057]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)Oct 10 20:12:31 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:629: Ecto.Adapters.SQL.raise_sql_call_error/1Oct 10 20:12:31 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:562: Ecto.Adapters.SQL.execute/5Oct 10 20:12:31 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:177: Ecto.Repo.Queryable.execute/4Oct 10 20:12:31 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3Oct 10 20:12:31 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/pagination.ex:33: Pleroma.Pagination.fetch_paginated/3Oct 10 20:12:31 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:964: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3Oct 10 20:12:31 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:356: Pleroma.Web.MastodonAPI.StatusController.favourites/2Oct 10 20:12:31 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:5: Pleroma.Web.MastodonAPI.StatusController.action/2Oct 10 20:12:43 neckbeard.xyz mix[93057]: 20:12:43.953 [error] Postgrex.Protocol (#PID<0.539.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.24817.9> timed out because it queued and checked out the connection for longer than 15000msOct 10 20:12:43 neckbeard.xyz mix[93057]: #PID<0.24817.9> was at location:Oct 10 20:12:43 neckbeard.xyz mix[93057]: :prim_inet.recv0/3Oct 10 20:12:43 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:2837: Postgrex.Protocol.msg_recv/4Oct 10 20:12:43 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1879: Postgrex.Protocol.recv_bind/3Oct 10 20:12:43 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1771: Postgrex.Protocol.bind_execute/4Oct 10 20:12:43 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection/holder.ex:293: DBConnection.Holder.holder_apply/4Oct 10 20:12:43 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1255: DBConnection.run_execute/5Oct 10 20:12:43 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1342: DBConnection.run/6Oct 10 20:12:43 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:596: DBConnection.execute/4Oct 10 20:12:43 neckbeard.xyz mix[93057]: 20:12:43.954 request_id=Fcx5ICFGbZan3W8ABmgi [error] Internal server error: %DBConnection.ConnectionError{message: "tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)", severity: :error}Oct 10 20:12:43 neckbeard.xyz mix[93057]: 20:12:43.955 [error] #PID<0.24817.9> running Pleroma.Web.Endpoint (connection #PID<0.24816.9>, stream id 1) terminatedOct 10 20:12:43 neckbeard.xyz mix[93057]: Server: neckbeard.xyz:80 (http)Oct 10 20:12:43 neckbeard.xyz mix[93057]: Request: GET /api/v1/favourites?since_id=9mtR902AqYpL2nAcTY&count=20&with_muted=trueOct 10 20:12:43 neckbeard.xyz mix[93057]: ** (exit) an exception was raised:Oct 10 20:12:43 neckbeard.xyz mix[93057]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)Oct 10 20:12:43 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:629: Ecto.Adapters.SQL.raise_sql_call_error/1Oct 10 20:12:43 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:562: Ecto.Adapters.SQL.execute/5Oct 10 20:12:43 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:177: Ecto.Repo.Queryable.execute/4Oct 10 20:12:43 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3Oct 10 20:12:43 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/pagination.ex:33: Pleroma.Pagination.fetch_paginated/3Oct 10 20:12:43 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:964: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3Oct 10 20:12:43 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:356: Pleroma.Web.MastodonAPI.StatusController.favourites/2Oct 10 20:12:43 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:5: Pleroma.Web.MastodonAPI.StatusController.action/2Oct 10 20:12:44 neckbeard.xyz mix[93057]: 20:12:44.599 [error] Postgrex.Protocol (#PID<0.530.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.24832.9> timed out because it queued and checked out the connection for longer than 15000msOct 10 20:12:44 neckbeard.xyz mix[93057]: #PID<0.24832.9> was at location:Oct 10 20:12:44 neckbeard.xyz mix[93057]: :prim_inet.recv0/3Oct 10 20:12:44 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:2837: Postgrex.Protocol.msg_recv/4Oct 10 20:12:44 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1879: Postgrex.Protocol.recv_bind/3Oct 10 20:12:44 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1771: Postgrex.Protocol.bind_execute/4Oct 10 20:12:44 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection/holder.ex:293: DBConnection.Holder.holder_apply/4Oct 10 20:12:44 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1255: DBConnection.run_execute/5Oct 10 20:12:44 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1342: DBConnection.run/6Oct 10 20:12:44 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:596: DBConnection.execute/4Oct 10 20:12:44 neckbeard.xyz mix[93057]: 20:12:44.600 request_id=Fcx5IEfEyS0XhO8ABs_B [error] Internal server error: %DBConnection.ConnectionError{message: "tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)", severity: :error}Oct 10 20:12:44 neckbeard.xyz mix[93057]: 20:12:44.602 [error] #PID<0.24832.9> running Pleroma.Web.Endpoint (connection #PID<0.24831.9>, stream id 1) terminatedOct 10 20:12:44 neckbeard.xyz mix[93057]: Server: neckbeard.xyz:80 (http)Oct 10 20:12:44 neckbeard.xyz mix[93057]: Request: GET /api/v1/favourites?count=20&with_muted=trueOct 10 20:12:44 neckbeard.xyz mix[93057]: ** (exit) an exception was raised:Oct 10 20:12:44 neckbeard.xyz mix[93057]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)Oct 10 20:12:44 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:629: Ecto.Adapters.SQL.raise_sql_call_error/1Oct 10 20:12:44 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:562: Ecto.Adapters.SQL.execute/5Oct 10 20:12:44 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:177: Ecto.Repo.Queryable.execute/4Oct 10 20:12:44 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3Oct 10 20:12:44 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/pagination.ex:33: Pleroma.Pagination.fetch_paginated/3Oct 10 20:12:44 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:964: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3Oct 10 20:12:44 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:356: Pleroma.Web.MastodonAPI.StatusController.favourites/2Oct 10 20:12:44 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:5: Pleroma.Web.MastodonAPI.StatusController.action/2Oct 10 20:12:46 neckbeard.xyz mix[93057]: 20:12:46.642 [error] Postgrex.Protocol (#PID<0.536.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.24887.9> timed out because it queued and checked out the connection for longer than 15000msOct 10 20:12:46 neckbeard.xyz mix[93057]: #PID<0.24887.9> was at location:Oct 10 20:12:46 neckbeard.xyz mix[93057]: :prim_inet.recv0/3Oct 10 20:12:46 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:2837: Postgrex.Protocol.msg_recv/4Oct 10 20:12:46 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1879: Postgrex.Protocol.recv_bind/3Oct 10 20:12:46 neckbeard.xyz mix[93057]: (postgrex) lib/postgrex/protocol.ex:1771: Postgrex.Protocol.bind_execute/4Oct 10 20:12:46 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection/holder.ex:293: DBConnection.Holder.holder_apply/4Oct 10 20:12:46 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1255: DBConnection.run_execute/5Oct 10 20:12:46 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:1342: DBConnection.run/6Oct 10 20:12:46 neckbeard.xyz mix[93057]: (db_connection) lib/db_connection.ex:596: DBConnection.execute/4Oct 10 20:12:46 neckbeard.xyz mix[93057]: 20:12:46.643 request_id=Fcx5IMFfEaPmS78ABmiC [error] Internal server error: %DBConnection.ConnectionError{message: "tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)", severity: :error}Oct 10 20:12:46 neckbeard.xyz mix[93057]: 20:12:46.645 [error] #PID<0.24887.9> running Pleroma.Web.Endpoint (connection #PID<0.24889.9>, stream id 1) terminatedOct 10 20:12:46 neckbeard.xyz mix[93057]: Server: neckbeard.xyz:80 (http)Oct 10 20:12:46 neckbeard.xyz mix[93057]: Request: GET /api/v1/favourites?count=20&with_muted=trueOct 10 20:12:46 neckbeard.xyz mix[93057]: ** (exit) an exception was raised:Oct 10 20:12:46 neckbeard.xyz mix[93057]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)Oct 10 20:12:46 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:629: Ecto.Adapters.SQL.raise_sql_call_error/1Oct 10 20:12:46 neckbeard.xyz mix[93057]: (ecto_sql) lib/ecto/adapters/sql.ex:562: Ecto.Adapters.SQL.execute/5Oct 10 20:12:46 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:177: Ecto.Repo.Queryable.execute/4Oct 10 20:12:46 neckbeard.xyz mix[93057]: (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3Oct 10 20:12:46 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/pagination.ex:33: Pleroma.Pagination.fetch_paginated/3Oct 10 20:12:46 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:964: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3Oct 10 20:12:46 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:356: Pleroma.Web.MastodonAPI.StatusController.favourites/2Oct 10 20:12:46 neckbeard.xyz mix[93057]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:5: Pleroma.Web.MastodonAPI.StatusController.action/2
(DIR) Post #9nnqfraP8ZGrPWA9nk by sjw@patch.cx
2019-10-11T03:16:31.931489Z
0 likes, 0 repeats
@saper @feld @lanodan @rin I can switch to debug logging if you need it.
(DIR) Post #9nov2suMywcJ96h6Tw by sjw@patch.cx
2019-10-11T15:40:12.732011Z
0 likes, 0 repeats
@feld @lanodan @rin @saper @sjw I just thought about it; I'm using RUM indexes. Not sure if that's important or not. Also, currently, the issue isn't happening. It only happens occasionally. So, maybe it's a specific app making specific API requests. Or, maybe it's because a user who uses something like blocks isn't on currently.I had pretty much this exact issue before and IIRC it was something about mutes being moved and linked but the index not being updated for that. @rin was able to figure out what it was and push a db migration that fixed it. That's why I was thinking it might be an index issue because it's very similar to last time.Sorry I didn't mention this last night. I was really tired and my thinking ability was debuffed.
(DIR) Post #9novDE4p8Gqlh9W0Gm by feld@bikeshed.party
2019-10-11T15:42:03.759972Z
2 likes, 0 repeats
@sjw @lanodan @rin @saper @sjw I'm also using RUM indexes, but I haven't seen this issue on my own server in a while.We have some more db optimizations to do and they're coming. Your feedback is appreciated. We don't want to ignore these issues.
(DIR) Post #9novNRsgfBqzP6iGNE by lain@pleroma.soykaf.com
2019-10-11T15:43:48.008484Z
0 likes, 0 repeats
@sjw @lanodan @rin the postgres planner might be confused. You could try running this : https://git.pleroma.social/pleroma/pleroma/merge_requests/1820be careful, it will take quite some time to run.
(DIR) Post #9nowCuZBlrIF8h8FVI by rin@patch.cx
2019-10-11T15:53:13.140545Z
1 likes, 0 repeats
@sjw @lanodan bruh, you have @ed me with this exact query at least 3 times during the past 2 weeks.but we probably have a solution now. please try running https://git.pleroma.social/pleroma/pleroma/merge_requests/1820 and seeing if it fixes it, note that it will take a while to migrate (1.5 hours on my 18gb database)
(DIR) Post #9noxIsH9IkkRj36LR2 by sjw@patch.cx
2019-10-11T16:05:31.430647Z
0 likes, 0 repeats
@lain @lanodan @rin I’ll give it a try. I just ran this long boi cd /opt/pleroma && sudo -Hu pleroma git pull && sudo -Hu pleroma git checkout object-id-column && sudo -Hu postgres /var/lib/postgres/pleroma.sh && sudo -Hu pleroma MIX_ENV=prod mix deps.get && sudo systemctl stop pleroma && sudo -Hu pleroma MIX_ENV=prod mix ecto.migrate && sudo systemctl start pleroma We’ll see how it goes. Making a backup of my DB before the migrations just in case.
(DIR) Post #9noxTVlPLBWD5jKJai by sjw@patch.cx
2019-10-11T16:07:26.135295Z
0 likes, 0 repeats
@rin @lanodan I know. Sorry about the spam. It's just been a pretty bad issue I've been trying to pin down and fix for a little while now :ablobsadpats:
(DIR) Post #9noxrtg25DcgCuRN8C by lain@pleroma.soykaf.com
2019-10-11T16:11:42.519704Z
1 likes, 0 repeats
@sjw @lanodan @rin also run a vacuum analyze after it's done and let the instance run for a while to warm all caches
(DIR) Post #9noy4e0vd3k3OUIDNg by sjw@patch.cx
2019-10-11T16:14:09.183621Z
0 likes, 0 repeats
@lain @lanodan @rin Will do. Would a vacuum full be recommended as well?
(DIR) Post #9noyFIUVzTZJpNDA80 by lain@pleroma.soykaf.com
2019-10-11T16:15:56.739283Z
2 likes, 0 repeats
@sjw @lanodan @rin that shouldn't make a difference
(DIR) Post #9np2xUv9XR5Qw50EmO by sjw@patch.cx
2019-10-11T17:08:52.534407Z
0 likes, 0 repeats
@lain @lanodan @rin Is there by any chance a way to see the progress of the migration? I just sort of want an idea of when I can expect it to be complete.
(DIR) Post #9np346rnMy12MOaLT6 by lain@pleroma.soykaf.com
2019-10-11T17:09:57.113763Z
1 likes, 0 repeats
@sjw @lanodan @rin no
(DIR) Post #9np3F3NSgOCYiwcCxM by sjw@patch.cx
2019-10-11T17:12:03.714759Z
1 likes, 0 repeats
@lain @lanodan @rin Oh well :cirnoShrug:
(DIR) Post #9np87kOPMuyvaUOSRc by sjw@patch.cx
2019-10-11T18:06:45.898731Z
0 likes, 0 repeats
@lain @lanodan @rin gg it’s done. Running VACUUM(ANALYSE); right now. Hopefully this will fix this issue.
(DIR) Post #9npPxychP50w0AZJqK by sjw@patch.cx
2019-10-11T21:26:40.981667Z
0 likes, 1 repeats
@lain @lanodan @rin Nope. It started again right at 4:02 PM CSTOct 11 14:23:45 neckbeard.xyz mix[915164]: Server: neckbeard.xyz:80 (http)Oct 11 14:23:45 neckbeard.xyz mix[915164]: Request: GET /api/v1/favourites?count=20&with_muted=trueOct 11 14:23:45 neckbeard.xyz mix[915164]: ** (exit) an exception was raised:Oct 11 14:23:45 neckbeard.xyz mix[915164]: ** (DBConnection.ConnectionError) tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)Oct 11 14:23:45 neckbeard.xyz mix[915164]: (ecto_sql) lib/ecto/adapters/sql.ex:629: Ecto.Adapters.SQL.raise_sql_call_error/1Oct 11 14:23:45 neckbeard.xyz mix[915164]: (ecto_sql) lib/ecto/adapters/sql.ex:562: Ecto.Adapters.SQL.execute/5Oct 11 14:23:45 neckbeard.xyz mix[915164]: (ecto) lib/ecto/repo/queryable.ex:177: Ecto.Repo.Queryable.execute/4Oct 11 14:23:45 neckbeard.xyz mix[915164]: (ecto) lib/ecto/repo/queryable.ex:17: Ecto.Repo.Queryable.all/3Oct 11 14:23:45 neckbeard.xyz mix[915164]: (pleroma) lib/pleroma/pagination.ex:33: Pleroma.Pagination.fetch_paginated/3Oct 11 14:23:45 neckbeard.xyz mix[915164]: (pleroma) lib/pleroma/web/activity_pub/activity_pub.ex:964: Pleroma.Web.ActivityPub.ActivityPub.fetch_activities/3Oct 11 14:23:45 neckbeard.xyz mix[915164]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:352: Pleroma.Web.MastodonAPI.StatusController.favourites/2Oct 11 14:23:45 neckbeard.xyz mix[915164]: (pleroma) lib/pleroma/web/mastodon_api/controllers/status_controller.ex:5: Pleroma.Web.MastodonAPI.StatusController.action/2Oct 11 14:23:47 neckbeard.xyz mix[915164]: 14:23:47.194 [error] Postgrex.Protocol (#PID<0.528.0>) disconnected: ** (DBConnection.ConnectionError) client #PID<0.29585.14> timed out because it queued and checked out the connection for longer than 15000msOct 11 14:23:47 neckbeard.xyz mix[915164]: #PID<0.29585.14> was at location:Oct 11 14:23:47 neckbeard.xyz mix[915164]: :prim_inet.recv0/3Oct 11 14:23:47 neckbeard.xyz mix[915164]: (postgrex) lib/postgrex/protocol.ex:2837: Postgrex.Protocol.msg_recv/4Oct 11 14:23:47 neckbeard.xyz mix[915164]: (postgrex) lib/postgrex/protocol.ex:1879: Postgrex.Protocol.recv_bind/3Oct 11 14:23:47 neckbeard.xyz mix[915164]: (postgrex) lib/postgrex/protocol.ex:1771: Postgrex.Protocol.bind_execute/4Oct 11 14:23:47 neckbeard.xyz mix[915164]: (db_connection) lib/db_connection/holder.ex:293: DBConnection.Holder.holder_apply/4Oct 11 14:23:47 neckbeard.xyz mix[915164]: (db_connection) lib/db_connection.ex:1255: DBConnection.run_execute/5Oct 11 14:23:47 neckbeard.xyz mix[915164]: (db_connection) lib/db_connection.ex:1342: DBConnection.run/6Oct 11 14:23:47 neckbeard.xyz mix[915164]: (db_connection) lib/db_connection.ex:596: DBConnection.execute/4Oct 11 14:23:47 neckbeard.xyz mix[915164]: 14:23:47.195 request_id=Fcy0qfKD_KJmvCYACokx [error] Internal server error: %DBConnection.ConnectionError{message: "tcp recv: closed (the connection was closed by the pool, possibly due to a timeout or because the pool has been terminated)", severity: :error}
(DIR) Post #9npQ7B5oPYzBHWZcMC by lain@pleroma.soykaf.com
2019-10-11T21:28:19.406693Z
0 likes, 0 repeats
@sjw @lanodan @rin this is just favorites, does this actually impact normal usage?
(DIR) Post #9npSl1tKF0IWEfraoi by sjw@patch.cx
2019-10-11T21:57:56.451102Z
1 likes, 0 repeats
@lain @lanodan @rin Normal usage because eventually it will stress the db to the point posts won’t load and you can’t post.Interestingly, I added a rewrite rule to nginx to remove with_muted=(.*) from /api/v1/favourites and cpu instantly dropped back down to normal.Here’s the rewrite I used: # Test drop mute location /api/v1/favourites { if ($query_string ~ "^(.*)with_muted=(.*)$") { rewrite ^(.*)$ $uri? redirect; } }So, it has something to do with mutes and some user, likely with a lot of mutes, trying to load it.So my guess is that the problem lies in mutes. Not sure if it’s with the index or not but mutes seem to stress postgres really hard. You can see exactly when I restarted nginx in this screenshot.image.png
(DIR) Post #9nqNVohEiDS8M75yMq by rin@patch.cx
2019-10-12T08:33:52.260829Z
1 likes, 0 repeats
@sjw @lain @lanodan literally all with_muted=true does is *remove* mute filtering, so I don't think it's the issue
(DIR) Post #9nqu1aLsmE71fQIdNY by sjw@patch.cx
2019-10-12T14:38:11.786108Z
0 likes, 0 repeats
@rin @lain @lanodan 🤷 It fixed the issue. looking into it, without that, naked /api/v1/favourites returns a 404 so maybe it's an issue with favourites.
(DIR) Post #9nszwfxGyblliA7ZcO by sjw@patch.cx
2019-10-13T14:53:57.695126Z
0 likes, 0 repeats
@rin @lain @sjw @lanodan This might be completely unrelated but I decided to run pg_repack on the DB and I got this warningNOTICE: Setting up workers.connsINFO: repacking table "public.activities"LOG: Initial worker 0 to build index: CREATE INDEX index_192510 ON repack.table_16579 USING btree (activity_visibility(actor, recipients, data), id DESC NULLS LAST) TABLESPACE pg_default WHERE ((data ->> 'type'::text) = 'Create'::text)LOG: Initial worker 1 to build index: CREATE UNIQUE INDEX index_192509 ON repack.table_16579 USING btree (((data ->> 'id'::text))) TABLESPACE pg_defaultLOG: Command finished in worker 0: CREATE INDEX index_192510 ON repack.table_16579 USING btree (activity_visibility(actor, recipients, data), id DESC NULLS LAST) TABLESPACE pg_default WHERE ((data ->> 'type'::text) = 'Create'::text)WARNING: Error with create index: ERROR: function activity_visibility(character varying, character varying[], jsonb) does not existLINE 1: ...X index_192510 ON repack.table_16579 USING btree (activity_v... ^HINT: No function matches the given name and argument types. You might need to add explicit type casts.
(DIR) Post #9nvTgJPQQ5yQ5tK2wy by sjw@patch.cx
2019-10-14T19:36:33.601112Z
0 likes, 0 repeats
@rin @lain @lanodan Looks like the issue was closed but now I'm on a different branch :ablobsadpats:https://git.pleroma.social/pleroma/pleroma/issues/1229