Re: FDW, too long to run explain
On Monday, 4 February 2019 09:14:14 EET Vijaykumar Jain wrote: > Hi, Hi, > with pg v10.1 > we use writes directly to shards, and reads via FDW from all shards (RO) > our DB size is ~ 500GB each shard, and tables are huge too. > 1 table ~ 200GB, 1 ~55GB, 1 ~40GB and a lot of small tables, but large > indices on large table. > > the sharding was done based on a key to enable shard isolation at app layer > using a fact table. > select id,shard from fact_table; > > server resources are, > 32GB mem, 8 vcpu, 500GB SSD. > > the FDW connect to each other shard via FDW fronted by haproxy -> pgbouncer > -> postgresql. > Hope this is good enough background :) > > now we have some long running queries via FDW that take minutes and get > killed explain runs as idle in transaction on remote servers. (we set > use_remote_estimate = true ) > when the query is run on individual shards directly, it runs pretty > quickly, > but when run via FDW, it takes very long. > i even altered fetch_sie to 1, so that in case some filters do not get > pushed, those can be applied on the FDW quickly. In general, the plans via FDW are not the same as the ones running locally. We're having similar issues and the reason seems to be that queries via FDW are optimized for startup cost or few rows. > Regards, > Vijay -- Regards, Peter
Trigger function always logs postgres as user name
Hi, I setup trigger functions for logging, and while they do work and get triggered, the current_user always insert “postgres” even when updates/deletes/inserts are caused by users of another name. How do I get it to use the name that caused the update? It seems current_user is the trigger’s user, so the server itself in some way. This is on PG10 Here the function: BEGIN IF TG_OP = 'INSERT' THEN INSERT INTO logging (tabname, schemaname, who, operation, new_val) VALUES (TG_RELNAME, TG_TABLE_SCHEMA, current_user, TG_OP, row_to_json(NEW)); RETURN NEW; ELSIF TG_OP = 'UPDATE' THEN INSERT INTO logging (tabname, schemaname, who, operation, new_val, old_val) VALUES (TG_RELNAME, TG_TABLE_SCHEMA, current_user, TG_OP, row_to_json(NEW), row_to_json(OLD)); RETURN NEW; ELSIF TG_OP = 'DELETE' THEN INSERT INTO logging (tabname, schemaname, operation, who, old_val) VALUES (TG_RELNAME, TG_TABLE_SCHEMA, TG_OP, current_user, row_to_json(OLD)); RETURN OLD; END IF; END; Cheers, Alex
Re: Trigger function always logs postgres as user name
Alexander: On Sat, Feb 9, 2019 at 1:32 PM Alexander Reichstadt wrote: > I setup trigger functions for logging, and while they do work and get > triggered, the current_user always insert “postgres” even when > updates/deletes/inserts are caused by users of another name. > How do I get it to use the name that caused the update? It seems current_user > is the trigger’s user, so the server itself in some way. This is on PG10 Maybe your trigger has been defined by postgres and you are using (from https://www.postgresql.org/docs/11/functions-info.html) current_user, name, user name of current execution context instead of session_user, name, session user name "The session_user is normally the user who initiated the current database connection; but superusers can change this setting with SET SESSION AUTHORIZATION. The current_user is the user identifier that is applicable for permission checking. Normally it is equal to the session user, but it can be changed with SET ROLE. It also changes during the execution of functions with the attribute SECURITY DEFINER. In Unix parlance, the session user is the “real user” and the current user is the “effective user”. current_role and user are synonyms for current_user. (The SQL standard draws a distinction between current_role and current_user, but PostgreSQL does not, since it unifies users and roles into a single kind of entity.)" Francisco Olarte.
Re: Server goes to Recovery Mode when run a SQL
Hi, On Fri, Feb 08, 2019 at 02:11:33PM -0700, PegoraroF10 wrote: > *Well, now we have two queries which stops completelly our postgres server. > That problem occurs on 10.6 and 11.1 versions. > On both server the problem is the same. > Linux logs of old crash are:* > Feb 1 18:39:53 fx-cloudserver kernel: [ 502.405788] show_signal_msg: 5 > callbacks suppressedFeb 1 18:39:53 fx-cloudserver kernel: [ 502.405791] > postgres[10195]: segfault at 24 ip 555dc6a71cb0 sp 7ffc5f91db38 > error 4 in postgres[555dc69b4000+6db000] "segfault" seems to mean you hit a bug, which we'll want more information to diagnose. Could you install debugging symbols ? Ubuntu calls their package postgresql-10-dbg or similar. And start server with coredumps enabled, using pg_ctl -c -D /var/lib/postgresql/10/main (or similar). Then trigger the query and hope to find a core dump in the data directory. Or possibly it'll be processed into /var/crash by apport daemon, depending if that's running and enabled (check /proc/sys/kernel/core_pattern). https://wiki.postgresql.org/wiki/Getting_a_stack_trace_of_a_running_PostgreSQL_backend_on_Linux/BSD#Getting_a_trace_from_a_randomly_crashing_backend > *Linux Log of new crash, which takes several minutes to stop:* > Feb 8 15:06:40 fxReplicationServer kernel: [1363901.643121] postgres > invoked oom-killer: gfp_mask=0x24280ca, order=0, oom_score_adj=0Feb 8 > fxReplicationServer kernel: [1363901.643368] Killed process 9399 (postgres) > total-vm:16518496kB, anon-rss:11997448kB, file-rss:38096kBFeb 8 17:21:16 > fxReplicationServer kernel: [1371977.845728] postgres[10321]: segfault at 10 > ip 5567a6069752 sp 7ffed70be970 error 4 in In this case, you ran out of RAM, as you noticed. You should make sure ANALYZE statistics are up to date (including manually ANALYZEing any parent tables). On Sun, Feb 03, 2019 at 09:05:42AM -0700, PegoraroF10 wrote: > I´m using Postgres 10 on ubuntu in a Google VM (8 cores, 32Gb RAM, 250Gb SSD) > and DB has 70GB What is work_mem setting ? You could try running the query with lower work_mem, or check EXPLAIN ANALYZE and try to resolve any bad rowcount estimates. > *This query runs for aproximately 5 minutes. See link above with images and > logs and you´ll see how memory will grow. Memory use starts with 8gb e grows > until use them all. When all memory is in use then it starts to swap. When > all swap is allocated then it gets the "out of memory" and stops > completelly. > on: https://drive.google.com/open?id=18zIvkV3ew4aZ1_cxI-EmIPVql7ydvEwi* It says "Access Denied", perhaps you could send a link to https://explain.depesz.com/ ? Justin
Re: query logging of prepared statements
On Fri, Feb 08, 2019 at 07:29:53AM -0600, Justin Pryzby wrote:
> A couple months ago, I implemented prepared statements for PyGreSQL. While
> updating our application in advance of their release with that feature, I
> noticed that our query logs were several times larger.
Previously sent to -general (and quoted fully below), resending to -hackers
with patch.
https://www.postgresql.org/message-id/20190208132953.GF29720%40telsasoft.com
I propose that the prepared statement associated with an EXECUTE should only be
included in log "DETAIL" when log_error_verbosity=VERBOSE, for both SQL EXECUTE
and PQexecPrepared. I'd like to be able to continue logging DETAIL (including
bind parameters), so want like to avoid setting "TERSE" just to avoid redundant
messages.
With attached patch, I'm not sure if !*portal_name && !portal->prepStmtName
would catch cases other than PQexecParams (?)
Compare unpatched server to patched server to patched server with
log_error_verbosity=verbose.
|$ psql postgres -xtc "SET log_error_verbosity=default;SET log_statement='all';
SET client_min_messages=log" -c "PREPARE q AS SELECT 2" -c "EXECUTE q"
|SET
|LOG: statement: PREPARE q AS SELECT 2
|PREPARE
|LOG: statement: EXECUTE q
|DETAIL: prepare: PREPARE q AS SELECT 2
|?column? | 2
|$ PGHOST=/tmp PGPORT=5678 psql postgres -xtc "SET
log_error_verbosity=default;SET log_statement='all'; SET
client_min_messages=log" -c "PREPARE q AS SELECT 2" -c "EXECUTE q"
|SET
|LOG: statement: PREPARE q AS SELECT 2
|PREPARE
|LOG: statement: EXECUTE q
|?column? | 2
|$ PGHOST=/tmp PGPORT=5678 psql postgres -xtc "SET
log_error_verbosity=verbose;SET log_statement='all'; SET
client_min_messages=log" -c "PREPARE q AS SELECT 2" -c "EXECUTE q"
|SET
|LOG: statement: PREPARE q AS SELECT 2
|PREPARE
|LOG: statement: EXECUTE q
|DETAIL: prepare: PREPARE q AS SELECT 2
|?column? | 2
For PQexecPrepared library call:
|$ xPGPORT=5678 xPGHOST=/tmp PYTHONPATH=../PyGreSQL/build/lib.linux-x86_64-2.7/
python2.7 -c "import pg; d=pg.DB('postgres'); d.query('SET
client_min_messages=log; SET log_error_verbosity=default; SET
log_statement=\"all\"'); d.query('SELECT 1; PREPARE q AS SELECT \$1');
d.query_prepared('q',[1]); d.query_formatted('SELECT %s', [2])"
|LOG: statement: SELECT 1; PREPARE q AS SELECT $1
|LOG: execute q: SELECT 1; PREPARE q AS SELECT $1
|DETAIL: parameters: $1 = '1'
|LOG: execute : SELECT $1
|DETAIL: parameters: $1 = '2'
|$ PGPORT=5678 PGHOST=/tmp PYTHONPATH=../PyGreSQL/build/lib.linux-x86_64-2.7/
python2.7 -c "import pg; d=pg.DB('postgres'); d.query('SET
client_min_messages=log; SET log_error_verbosity=default; SET
log_statement=\"all\"'); d.query('SELECT 1; PREPARE q AS SELECT \$1');
d.query_prepared('q',[1]); d.query_formatted('SELECT %s', [2])"
|LOG: statement: SELECT 1; PREPARE q AS SELECT $1
|LOG: execute q
|DETAIL: parameters: $1 = '1'
|LOG: execute : SELECT $1
|DETAIL: parameters: $1 = '2'
|$ PGPORT=5678 PGHOST=/tmp PYTHONPATH=../PyGreSQL/build/lib.linux-x86_64-2.7/
python2.7 -c "import pg; d=pg.DB('postgres'); d.query('SET
client_min_messages=log; SET log_error_verbosity=verbose; SET
log_statement=\"all\"'); d.query('SELECT 1; PREPARE q AS SELECT \$1');
d.query_prepared('q',[1]); d.query_formatted('SELECT %s', [2])"
|LOG: statement: SELECT 1; PREPARE q AS SELECT $1
|LOG: execute q: SELECT 1; PREPARE q AS SELECT $1
|DETAIL: parameters: $1 = '1'
|LOG: execute : SELECT $1
|DETAIL: parameters: $1 = '2'
Also, I noticed that if the statement was prepared using SQL PREPARE (rather
than PQprepare), and if it used simple query with multiple commands, they're
all included in the log, like this when executed with PQexecPrepared:
|LOG: execute q: SET log_error_verbosity=verbose; SET client_min_messages=log;
PREPARE q AS SELECT $1
And looks like this for SQL EXECUTE:
|[pryzbyj@telsasoft-db postgresql]$ psql postgres -txc "SET
client_min_messages=log;SELECT 1;PREPARE q AS SELECT 2" -c "EXECUTE q"
|PREPARE
|LOG: statement: EXECUTE q
|DETAIL: prepare: SET client_min_messages=log;SELECT 1;PREPARE q AS SELECT 2
|?column? | 2
On Fri, Feb 08, 2019 at 07:29:53AM -0600, Justin Pryzby wrote:
> A couple months ago, I implemented prepared statements for PyGreSQL. While
> updating our application in advance of their release with that feature, I
> noticed that our query logs were several times larger.
>
> With non-prepared statements, we logged to CSV:
> |message| SELECT 1
>
> With SQL EXECUTE, we log:
> |message| statement: EXECUTE sqlex(2);
> |detail | prepare: prepare sqlex AS SELECT $1;
>
> With PQexecPrepared, we would log:
> |message| execute qq: PREPARE qq AS SELECT $1
> |detail | parameters: $1 = '3'
>
> For comparison, with PQexecParams, the logs I see look like this (apparently
> the "unnamed" prepared statement is used behind the scenes):
> |message| execute : SELECT [...]
>
> It's not clear to me why it'd be desira
Re: Server goes to Recovery Mode when run a SQL
Hi, On Sat, 2019-02-09 at 15:46 -0600, Justin Pryzby wrote: > Hi, > > > > "segfault" seems to mean you hit a bug, which we'll want more > information to > diagnose. Could you install debugging symbols ? Ubuntu calls their > package > postgresql-10-dbg or similar. And start server with coredumps > enabled, using > pg_ctl -c -D /var/lib/postgresql/10/main (or similar). Then trigger > the query > and hope to find a core dump in the data directory. Or possibly > it'll be > processed into /var/crash by apport daemon, depending if that's > running and > enabled (check /proc/sys/kernel/core_pattern). > I believe there is a bug. I've examined the query Marcos sent with his first post and I think the parser should have listed some errors and not tried to run the query. I'm probably wrong but consider the following. Around line 33 of the query:- tsrange(col_aula.data, (col_aula.data + (col_aula.tempo|| ' minute')::interval)) dia, 0 prevista, (extract(EPOCH FROM col_aula.tempo) / 60) minutosassistidos Assuming column col_aula.tempo is of type INTEGER, is NOT NULL and let's say contains a value of 60, then it parses as tsrange(col_aula.data, (col_aula.data + (60' minute')::interval)) which would pull a syntax error. You cannot extract EPOCH from a column that is of type INTEGER. Another syntax error. Down around line 87 onwards there are generate_series without any parameters, and further dubious usage of EPOCH, as well as DOW. Not having the table definitions is obviously clouding the analysis. If there is a bug in the parser, then one of the experts will have to opine about that. HTH, Robert
