profiler/controllers/main.py
# coding: utf-8
# License AGPL-3 or later (http://www.gnu.org/licenses/lgpl).
# Copyright 2014 Anybox <http://anybox.fr>
# Copyright 2016 Vauxoo (https://www.vauxoo.com) <info@vauxoo.com>
import errno
import logging
import os
import sys
import tempfile
from cStringIO import StringIO
from datetime import datetime
from openerp import http, sql_db, tools
from openerp.addons.web.controllers.main import content_disposition
from openerp.http import request
from openerp.service.db import dump_db_manifest
from openerp.tools.misc import find_in_path
from ..hooks import CoreProfile as core
_logger = logging.getLogger(__name__)
try:
from pstats_print2list import get_pstats_print2list, print_pstats_list
except ImportError as err: # pragma: no cover
_logger.debug(err)
DFTL_LOG_PATH = '/var/lib/postgresql/%s/main/pg_log/postgresql.log'
PGOPTIONS = (
'-c client_min_messages=notice -c log_min_messages=warning '
'-c log_min_error_statement=error '
'-c log_min_duration_statement=0 -c log_connections=on '
'-c log_disconnections=on -c log_duration=off '
'-c log_error_verbosity=verbose -c log_lock_waits=on '
'-c log_statement=none -c log_temp_files=0 '
)
class Capturing(list):
def __enter__(self):
self._stdout = sys.stdout
sys.stdout = self._stringio = StringIO()
return self
def __exit__(self, *args):
self.extend(self._stringio.getvalue().splitlines())
del self._stringio # free up some memory
sys.stdout = self._stdout
class ProfilerController(http.Controller):
_cp_path = '/web/profiler'
player_state = 'profiler_player_clear'
begin_date = ''
end_date = ''
"""Indicate the state(css class) of the player:
* profiler_player_clear
* profiler_player_enabled
* profiler_player_disabled
"""
@http.route(['/web/profiler/enable'], type='json', auth="user")
def enable(self):
_logger.info("Enabling")
core.enabled = True
ProfilerController.begin_date = datetime.now().strftime(
"%Y-%m-%d %H:%M:%S")
ProfilerController.player_state = 'profiler_player_enabled'
os.environ['PGOPTIONS'] = PGOPTIONS
self.empty_cursor_pool()
@http.route(['/web/profiler/disable'], type='json', auth="user")
def disable(self, **post):
_logger.info("Disabling")
core.enabled = False
ProfilerController.end_date = datetime.now().strftime(
"%Y-%m-%d %H:%M:%S")
ProfilerController.player_state = 'profiler_player_disabled'
os.environ.pop("PGOPTIONS", None)
self.empty_cursor_pool()
@http.route(['/web/profiler/clear'], type='json', auth="user")
def clear(self, **post):
core.profile.clear()
_logger.info("Cleared stats")
ProfilerController.player_state = 'profiler_player_clear'
ProfilerController.end_date = ''
ProfilerController.begin_date = ''
@http.route(['/web/profiler/dump'], type='http', auth="user")
def dump(self, token, **post):
"""Provide the stats as a file download.
Uses a temporary file, because apparently there's no API to
dump stats in a stream directly.
"""
exclude_fname = self.get_exclude_fname()
with tools.osutil.tempdir() as dump_dir:
ts = datetime.now().strftime("%Y-%m-%d_%H-%M-%S")
filename = 'openerp_%s' % ts
stats_path = os.path.join(dump_dir, '%s.stats' % filename)
core.profile.dump_stats(stats_path)
_logger.info("Pstats Command:")
params = {'fnames': stats_path, 'sort': 'cumulative', 'limit': 45,
'exclude_fnames': exclude_fname}
_logger.info(
"fnames=%(fnames)s, sort=%(sort)s,"
" limit=%(limit)s, exclude_fnames=%(exclude_fnames)s", params)
pstats_list = get_pstats_print2list(**params)
with Capturing() as output:
print_pstats_list(pstats_list)
result_path = os.path.join(dump_dir, '%s.txt' % filename)
with open(result_path, "a") as res_file:
for line in output:
res_file.write('%s\n' % line)
# PG_BADGER
self.dump_pgbadger(dump_dir, 'pgbadger_output.txt', request.cr)
t_zip = tempfile.TemporaryFile()
tools.osutil.zip_dir(dump_dir, t_zip, include_dir=False)
t_zip.seek(0)
headers = [
('Content-Type', 'application/octet-stream; charset=binary'),
('Content-Disposition', content_disposition(
'%s.zip' % filename))]
_logger.info('Download Profiler zip: %s', t_zip.name)
return request.make_response(
t_zip, headers=headers, cookies={'fileToken': token})
@http.route(['/web/profiler/initial_state'], type='json', auth="user")
def initial_state(self, **post):
user = request.env['res.users'].browse(request.uid)
return {
'has_player_group': user.has_group(
'profiler.group_profiler_player'),
'player_state': ProfilerController.player_state,
}
def dump_pgbadger(self, dir_dump, output, cursor):
pgbadger = find_in_path("pgbadger")
if not pgbadger:
_logger.error("Pgbadger not found")
return
filename = os.path.join(dir_dump, output)
pg_version = dump_db_manifest(cursor)['pg_version']
log_path = os.environ.get('PG_LOG_PATH', DFTL_LOG_PATH % pg_version)
if not os.path.exists(os.path.dirname(filename)):
try:
os.makedirs(os.path.dirname(filename))
except OSError as exc:
# error is different than File exists
if exc.errno != errno.EEXIST:
_logger.error("Folder %s can not be created",
os.path.dirname(filename))
return
_logger.info("Generating PG Badger report.")
exclude_query = self.get_exclude_query()
dbname = cursor.dbname
command = [
pgbadger, '-f', 'stderr', '-T', 'Odoo-Profiler',
'-o', '-', '-d', dbname, '-b', ProfilerController.begin_date,
'-e', ProfilerController.end_date, '--sample', '2',
'--disable-type', '--disable-error', '--disable-hourly',
'--disable-session', '--disable-connection',
'--disable-temporary', '--quiet']
command.extend(exclude_query)
command.append(log_path)
_logger.info("Pgbadger Command:")
_logger.info(command)
result = tools.exec_command_pipe(*command)
with open(filename, 'w') as fw:
fw.write(result[1].read())
_logger.info("Done")
def get_exclude_fname(self):
efnameid = request.env.ref(
'profiler.default_exclude_fnames_pstas', raise_if_not_found=False)
if not efnameid:
return []
return [os.path.expanduser(path)
for path in efnameid and efnameid.value.strip(',').split(',')
if path]
def get_exclude_query(self):
"""Example '^(COPY|COMMIT)'
"""
equeryid = request.env.ref(
'profiler.default_exclude_query_pgbadger',
raise_if_not_found=False)
if not equeryid:
return []
exclude_queries = []
for path in equeryid and equeryid.value.strip(',').split(','):
exclude_queries.extend(
['--exclude-query', '"^(%s)" ' % path.encode('UTF-8')])
return exclude_queries
def empty_cursor_pool(self):
"""This method cleans (rollback) all current transactions over actual
cursor in order to avoid errors with waiting transactions.
- request.cr.rollback()
Also connections on current database's only are closed by the next
statement
- dsn = openerp.sql_db.dsn(request.cr.dbname)
- openerp.sql_db._Pool.close_all(dsn[1])
Otherwise next error will be trigger
'InterfaceError: connection already closed'
Finally new cursor is assigned to the request object, this cursor will
take the os.environ setted. In this case the os.environ is setted with
all 'PGOPTIONS' required to log all sql transactions in postgres.log
file.
If this method is called one more time, it will create a new cursor and
take the os.environ again, this is usefully if we want to reset
'PGOPTIONS'
"""
request.cr._cnx.reset()
dsn = sql_db.dsn(request.cr.dbname)
sql_db._Pool.close_all(dsn[1])
db = sql_db.db_connect(request.cr.dbname)
request._cr = db.cursor()