X Tutup
Skip to content

Commit fe52d7f

Browse files
kk7dskk7ds
committed
Change DB counting mechanism
The mysql performance_schema method for counting per-database queries is very heavyweight in that it requires full logging (in a table) of every query. We do hundreds of thousands in the course of a tempest run, which ends up creating its own performance problem. This changes the approach we take, which is to bundle a very tiny sqlalchemy plugin module which counts just what we care about in a special database. It is more complex than just enabling the features in mysql, but it is a massively smaller runtime overhead. It also provides us the opportunity to easily zero the counters just before a tempest run. Change-Id: I361bc30bb970cdaf18b966951f217862d302f0b9
1 parent d450e14 commit fe52d7f

File tree

6 files changed

+173
-11
lines changed

6 files changed

+173
-11
lines changed

‎lib/databases/mysql‎

Lines changed: 21 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -151,12 +151,16 @@ function configure_database_mysql {
151151
fi
152152

153153
if [[ "$MYSQL_GATHER_PERFORMANCE" == "True" ]]; then
154-
echo "enabling MySQL performance_schema items"
155-
# Enable long query history
156-
iniset -sudo $my_conf mysqld \
157-
performance-schema-consumer-events-statements-history-long TRUE
158-
iniset -sudo $my_conf mysqld \
159-
performance_schema_events_stages_history_long_size 1000000
154+
echo "enabling MySQL performance counting"
155+
156+
# Install our sqlalchemy plugin
157+
pip_install ${TOP_DIR}/tools/dbcounter
158+
159+
# Create our stats database for accounting
160+
recreate_database stats
161+
mysql -u $DATABASE_USER -p$DATABASE_PASSWORD -h $MYSQL_HOST -e \
162+
"CREATE TABLE queries (db VARCHAR(32), op VARCHAR(32),
163+
count INT, PRIMARY KEY (db, op)) ENGINE MEMORY" stats
160164
fi
161165

162166
restart_service $MYSQL_SERVICE_NAME
@@ -218,7 +222,17 @@ function install_database_python_mysql {
218222

219223
function database_connection_url_mysql {
220224
local db=$1
221-
echo "$BASE_SQL_CONN/$db?charset=utf8"
225+
local plugin
226+
227+
# NOTE(danms): We don't enable perf on subnodes yet because the
228+
# plugin is not installed there
229+
if [[ "$MYSQL_GATHER_PERFORMANCE" == "True" ]]; then
230+
if is_service_enabled mysql; then
231+
plugin="&plugin=dbcounter"
232+
fi
233+
fi
234+
235+
echo "$BASE_SQL_CONN/$db?charset=utf8$plugin"
222236
}
223237

224238

‎stack.sh‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1512,6 +1512,19 @@ async_cleanup
15121512
time_totals
15131513
async_print_timing
15141514

1515+
if is_service_enabled mysql; then
1516+
if [[ "$MYSQL_GATHER_PERFORMANCE" == "True" && "$MYSQL_HOST" ]]; then
1517+
echo ""
1518+
echo ""
1519+
echo "Post-stack database query stats:"
1520+
mysql -u $DATABASE_USER -p$DATABASE_PASSWORD -h $MYSQL_HOST stats -e \
1521+
'SELECT * FROM queries' -t 2>/dev/null
1522+
mysql -u $DATABASE_USER -p$DATABASE_PASSWORD -h $MYSQL_HOST stats -e \
1523+
'DELETE FROM queries' 2>/dev/null
1524+
fi
1525+
fi
1526+
1527+
15151528
# Using the cloud
15161529
# ===============
15171530

‎tools/dbcounter/dbcounter.py‎

Lines changed: 120 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
import json
2+
import logging
3+
import os
4+
import threading
5+
import time
6+
import queue
7+
8+
import sqlalchemy
9+
from sqlalchemy.engine import CreateEnginePlugin
10+
from sqlalchemy import event
11+
12+
# https://docs.sqlalchemy.org/en/14/core/connections.html?
13+
# highlight=createengineplugin#sqlalchemy.engine.CreateEnginePlugin
14+
15+
LOG = logging.getLogger(__name__)
16+
17+
# The theory of operation here is that we register this plugin with
18+
# sqlalchemy via an entry_point. It gets loaded by virtue of plugin=
19+
# being in the database connection URL, which gives us an opportunity
20+
# to hook the engines that get created.
21+
#
22+
# We opportunistically spawn a thread, which we feed "hits" to over a
23+
# queue, and which occasionally writes those hits to a special
24+
# database called 'stats'. We access that database with the same user,
25+
# pass, and host as the main connection URL for simplicity.
26+
27+
28+
class LogCursorEventsPlugin(CreateEnginePlugin):
29+
def __init__(self, url, kwargs):
30+
self.db_name = url.database
31+
LOG.info('Registered counter for database %s' % self.db_name)
32+
new_url = sqlalchemy.engine.URL.create(url.drivername,
33+
url.username,
34+
url.password,
35+
url.host,
36+
url.port,
37+
'stats')
38+
39+
self.engine = sqlalchemy.create_engine(new_url)
40+
self.queue = queue.Queue()
41+
self.thread = None
42+
43+
def engine_created(self, engine):
44+
"""Hook the engine creation process.
45+
46+
This is the plug point for the sqlalchemy plugin. Using
47+
plugin=$this in the URL causes this method to be called when
48+
the engine is created, giving us a chance to hook it below.
49+
"""
50+
event.listen(engine, "before_cursor_execute", self._log_event)
51+
52+
def ensure_writer_thread(self):
53+
self.thread = threading.Thread(target=self.stat_writer, daemon=True)
54+
self.thread.start()
55+
56+
def _log_event(self, conn, cursor, statement, parameters, context,
57+
executemany):
58+
"""Queue a "hit" for this operation to be recorded.
59+
60+
Attepts to determine the operation by the first word of the
61+
statement, or 'OTHER' if it cannot be determined.
62+
"""
63+
64+
# Start our thread if not running. If we were forked after the
65+
# engine was created and this plugin was associated, our
66+
# writer thread is gone, so respawn.
67+
if not self.thread or not self.thread.is_alive():
68+
self.ensure_writer_thread()
69+
70+
try:
71+
op = statement.strip().split(' ', 1)[0] or 'OTHER'
72+
except Exception:
73+
op = 'OTHER'
74+
75+
self.queue.put((self.db_name, op))
76+
77+
def do_incr(self, db, op, count):
78+
"""Increment the counter for (db,op) by count."""
79+
80+
query = ('INSERT INTO queries (db, op, count) '
81+
' VALUES (%s, %s, %s) '
82+
' ON DUPLICATE KEY UPDATE count=count+%s')
83+
try:
84+
with self.engine.begin() as conn:
85+
r = conn.execute(query, (db, op, count, count))
86+
except Exception as e:
87+
LOG.error('Failed to account for access to database %r: %s',
88+
db, e)
89+
90+
def stat_writer(self):
91+
"""Consume messages from the queue and write them in batches.
92+
93+
This reads "hists" from from a queue fed by _log_event() and
94+
writes (db,op)+=count stats to the database after ten seconds
95+
of no activity to avoid triggering a write for every SELECT
96+
call. Write no less often than every thirty seconds and/or 100
97+
pending hits to avoid being starved by constant activity.
98+
"""
99+
LOG.debug('[%i] Writer thread running' % os.getpid())
100+
while True:
101+
to_write = {}
102+
total = 0
103+
last = time.time()
104+
while time.time() - last < 30 and total < 100:
105+
try:
106+
item = self.queue.get(timeout=10)
107+
to_write.setdefault(item, 0)
108+
to_write[item] += 1
109+
total += 1
110+
except queue.Empty:
111+
break
112+
113+
if to_write:
114+
LOG.debug('[%i] Writing DB stats %s' % (
115+
os.getpid(),
116+
','.join(['%s:%s=%i' % (db, op, count)
117+
for (db, op), count in to_write.items()])))
118+
119+
for (db, op), count in to_write.items():
120+
self.do_incr(db, op, count)

‎tools/dbcounter/pyproject.toml‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,3 @@
1+
[build-system]
2+
requires = ["sqlalchemy", "setuptools>=42"]
3+
build-backend = "setuptools.build_meta"

‎tools/dbcounter/setup.cfg‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
[metadata]
2+
name = dbcounter
3+
author = Dan Smith
4+
author_email = dms@danplanet.com
5+
version = 0.1
6+
description = A teeny tiny dbcounter plugin for use with devstack
7+
url = http://github.com/openstack/devstack
8+
license = Apache
9+
10+
[options]
11+
modules = dbcounter
12+
entry_points =
13+
[sqlalchemy.plugins]
14+
dbcounter = dbcounter:LogCursorEventsPlugin

‎tools/get-stats.py‎

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -83,13 +83,11 @@ def proc_matches(proc):
8383
def get_db_stats(host, user, passwd):
8484
dbs = []
8585
db = pymysql.connect(host=host, user=user, password=passwd,
86-
database='performance_schema',
86+
database='stats',
8787
cursorclass=pymysql.cursors.DictCursor)
8888
with db:
8989
with db.cursor() as cur:
90-
cur.execute(
91-
'SELECT COUNT(*) AS queries,current_schema AS db FROM '
92-
'events_statements_history_long GROUP BY current_schema')
90+
cur.execute('SELECT db,op,count FROM queries')
9391
for row in cur:
9492
dbs.append({k: tryint(v) for k, v in row.items()})
9593
return dbs

0 commit comments

Comments
 (0)
X Tutup