process_fts_updates: Clean up logging output.

This saves a couple lines of spammy output in the run-dev.py startup
experience, and will be better output in production as well.
This commit is contained in:
Tim Abbott
2020-05-01 11:51:18 -07:00
parent ce55ef6e4f
commit 4f3976b917
2 changed files with 23 additions and 11 deletions

View File

@@ -22,6 +22,7 @@ try:
except ImportError: except ImportError:
pass pass
import argparse
import psycopg2 import psycopg2
import psycopg2.extensions import psycopg2.extensions
import select import select
@@ -33,6 +34,19 @@ import os
BATCH_SIZE = 1000 BATCH_SIZE = 1000
parser = argparse.ArgumentParser()
parser.add_argument('--quiet',
action='store_true')
options = parser.parse_args()
logging.Formatter.converter = time.gmtime
logging.basicConfig(format="%(asctime)s %(levelname)s: %(message)s")
logger = logging.getLogger("process_fts_updates")
if options.quiet:
logger.setLevel(logging.INFO)
else:
logger.setLevel(logging.DEBUG)
def update_fts_columns(cursor: psycopg2.extensions.cursor) -> int: def update_fts_columns(cursor: psycopg2.extensions.cursor) -> int:
cursor.execute("SELECT id, message_id FROM fts_update_log LIMIT %s;" % ( cursor.execute("SELECT id, message_id FROM fts_update_log LIMIT %s;" % (
BATCH_SIZE,)) BATCH_SIZE,))
@@ -55,13 +69,6 @@ def am_master(cursor: psycopg2.extensions.cursor) -> bool:
cursor.execute("SELECT pg_is_in_recovery()") cursor.execute("SELECT pg_is_in_recovery()")
return not cursor.fetchall()[0][0] return not cursor.fetchall()[0][0]
logging.Formatter.converter = time.gmtime
logging.basicConfig(format="%(asctime)s %(levelname)s: %(message)s")
logger = logging.getLogger("process_fts_updates")
logger.setLevel(logging.DEBUG)
logger.info("process_fts_updates starting")
pg_args = {} pg_args = {}
# Path to the root of the Zulip codebase in production # Path to the root of the Zulip codebase in production
@@ -124,16 +131,21 @@ while True:
while not am_master(cursor): while not am_master(cursor):
if first_check: if first_check:
first_check = False first_check = False
logger.info("In recovery; sleeping") logger.warning("In recovery; sleeping")
time.sleep(5) time.sleep(5)
logger.info("Not in recovery; listening for FTS updates") logger.info("process_fts_updates: listening for search index updates")
cursor.execute("LISTEN fts_update_log;") cursor.execute("LISTEN fts_update_log;")
# Catch up on any historical columns # Catch up on any historical columns
while True: while True:
rows_updated = update_fts_columns(cursor) rows_updated = update_fts_columns(cursor)
logger.info("Processed %s rows catching up" % (rows_updated,)) notice = "Processed %s rows catching up" % (rows_updated,)
if rows_updated > 0:
logger.info(notice)
else:
logger.debug(notice)
if rows_updated != BATCH_SIZE: if rows_updated != BATCH_SIZE:
# We're caught up, so proceed to the listening for updates phase. # We're caught up, so proceed to the listening for updates phase.
break break

View File

@@ -155,7 +155,7 @@ def server_processes() -> List[List[str]]:
other_cmds = [ other_cmds = [
['./manage.py', 'process_queue', '--all'] + manage_args, ['./manage.py', 'process_queue', '--all'] + manage_args,
['env', 'PGHOST=127.0.0.1', # Force password authentication using .pgpass ['env', 'PGHOST=127.0.0.1', # Force password authentication using .pgpass
'./puppet/zulip/files/postgresql/process_fts_updates'], './puppet/zulip/files/postgresql/process_fts_updates', '--quiet'],
['./manage.py', 'deliver_scheduled_messages'], ['./manage.py', 'deliver_scheduled_messages'],
['/srv/zulip-thumbor-venv/bin/thumbor', '-c', './zthumbor/thumbor.conf', ['/srv/zulip-thumbor-venv/bin/thumbor', '-c', './zthumbor/thumbor.conf',
'-p', '%s' % (thumbor_port,)], '-p', '%s' % (thumbor_port,)],