Bug 1508989

Summary:	Queue workers are frequently querying pg_backend_pid
Product:	Red Hat CloudForms Management Engine	Reporter:	Joe Rafaniello <jrafanie>
Component:	Appliance	Assignee:	Joe Rafaniello <jrafanie>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Dave Johnson <dajohnso>
Severity:	medium	Docs Contact:
Priority:	medium
Version:	5.7.0	CC:	abellott, jhardy, obarenbo, simaishi
Target Milestone:	GA	Keywords:	TestOnly
Target Release:	5.10.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:	5.10.0.0	Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:
Clones:	1509418 1509419 1509420 (view as bug list)		Environment:
Last Closed:	2018-06-21 21:12:08 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:
Bug Depends On:
Bug Blocks:	1509418, 1509419, 1509420

Description Joe Rafaniello 2017-11-02 15:54:05 UTC

Description of problem: In development mode, we noticed that processes were almost continually querying pg_backend_pid to get the process' backend postgresql pid.  In production mode, you need to enable debug level_rails log level to see that it's also happening in production.


Version-Release number of selected component (if applicable):


How reproducible: This happens on each queue message a queue worker processes.


Steps to Reproduce:
1.  rake evm:start.  In production mode, you need to change level_rails log level to debug in advanced settings to see it.
2.  tail -f log/development.log
3.  See the queries for pg_backend_pid

Actual results: Lots of SELECT pg_backend_pid() queries per minute


Expected results:  Much less queries.


Additional info:
[----] D, [2017-11-02T11:26:00.379303 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:03.383988 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:06.388880 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:09.392199 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:12.398854 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:12.427565 #77001:3fcce043f7b4] DEBUG -- :    (0.3ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:12.439136 #77001:3fcce043f7b4] DEBUG -- :    (0.3ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:15.443631 #77001:3fcce043f7b4] DEBUG -- :    (0.6ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:18.446966 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:21.452259 #77001:3fcce043f7b4] DEBUG -- :    (0.6ms)  SELECT pg_backend_pid()
[----] D, [2017-11-02T11:26:24.459287 #77001:3fcce043f7b4] DEBUG -- :    (0.5ms)  SELECT pg_backend_pid()

Comment 2 Joe Rafaniello 2017-11-02 15:55:49 UTC

This has been in the queue worker code base since:

commit fbf3233daefe45c97f18bb486bfdade55ab371f3
Author: <REDACTED>
Date:   Fri May 11 23:49:33 2012 +0000

    If worker gets killed, a kill spid request should be sent to SQL
    - Created sql_spid column for MiqWorker (in reserves table)
    - Populate sql_spid column when worker starts, dequeues message, or releases db connection
    - Added kill methods to Postgres and SQL Server ActiveRecord adapters
    - Fixed PG spid method to return a number, instead of a string in an array.
    BugzID:14803

    git-svn-id: http://miq-ubuntusub.manageiq.com/svn/svnrepos/Manageiq/trunk@35274 3c68ef56-dcc3-11dc-9475-a42b84ecc76f

Comment 3 CFME Bot 2017-11-02 16:11:47 UTC

https://github.com/ManageIQ/manageiq/pull/16384

Comment 4 CFME Bot 2017-11-02 17:46:51 UTC

New commit detected on ManageIQ/manageiq/master:
https://github.com/ManageIQ/manageiq/commit/e3839397eb238652c4624449fe8b172bfc2f2745

commit e3839397eb238652c4624449fe8b172bfc2f2745
Author:     Joe Rafaniello <jrafanie>
AuthorDate: Thu Nov 2 11:57:33 2017 -0400
Commit:     Joe Rafaniello <jrafanie>
CommitDate: Thu Nov 2 12:00:39 2017 -0400

    update_spid! on timeout, not on each message
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1508989
    
    We were issuing many redundant queries per minute per queue worker
    process because the spid will not change that often.
    
    It was originally added a long time ago in:
    commit fbf3233daefe45c97f18bb486bfdade55ab371f3
    Date:   Fri May 11 23:49:33 2012 +0000
    BugzID:14803
    
    We can eliminate these queries and only do it when we actually
    reconnect! following a timeout.

 app/models/miq_queue_worker_base/runner.rb | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Comment 5 Joe Rafaniello 2017-11-02 18:06:33 UTC

Note, recreate this on appliances, you don't even need to run rake evm:start, just systemctl start evmserverd, change the level_rails in the advanced settings to debug and watch the generic/priority/(other queue workers) pids in the log/production.log.