Fix logging and add some basic verbosity
- Fix CLI logging - Add debug logging for reports - The SQLAlchemy Echo parameter is now properly documented - The Debug view is now controller by the loglevel Change-Id: I7a0f43c3e2a280538fc372f31e3252edee76c882
This commit is contained in:
parent
3c91da4087
commit
21b18a8707
|
@ -41,6 +41,12 @@ class BaseConfig(object):
|
|||
)
|
||||
self.SQLALCHEMY_DATABASE_URI = self.ARA_DATABASE
|
||||
self.SQLALCHEMY_TRACK_MODIFICATIONS = False
|
||||
self.SQLALCHEMY_ECHO = ara_config(
|
||||
'sqlalchemy_echo',
|
||||
'SQLALCHEMY_ECHO',
|
||||
False,
|
||||
value_type='boolean'
|
||||
)
|
||||
self.SQLALCHEMY_POOL_SIZE = ara_config(
|
||||
'sqlalchemy_pool_size',
|
||||
'SQLALCHEMY_POOL_SIZE',
|
||||
|
|
|
@ -30,18 +30,16 @@ version: 1
|
|||
formatters:
|
||||
normal:
|
||||
format: '%(asctime)s %(levelname)s %(name)s: %(message)s'
|
||||
console:
|
||||
format: '%(asctime)s %(levelname)s %(name)s: %(message)s'
|
||||
handlers:
|
||||
console:
|
||||
class: logging.StreamHandler
|
||||
formatter: console
|
||||
formatter: normal
|
||||
level: INFO
|
||||
stream: ext://sys.stdout
|
||||
normal:
|
||||
file:
|
||||
class: logging.handlers.TimedRotatingFileHandler
|
||||
formatter: normal
|
||||
level: DEBUG
|
||||
level: {level}
|
||||
filename: '{dir}/{file}'
|
||||
when: 'midnight'
|
||||
interval: 1
|
||||
|
@ -49,31 +47,29 @@ handlers:
|
|||
loggers:
|
||||
ara:
|
||||
handlers:
|
||||
- console
|
||||
- normal
|
||||
- file
|
||||
level: {level}
|
||||
propagate: 0
|
||||
alembic:
|
||||
handlers:
|
||||
- console
|
||||
- normal
|
||||
- file
|
||||
level: WARN
|
||||
propagate: 0
|
||||
sqlalchemy.engine:
|
||||
handlers:
|
||||
- console
|
||||
- normal
|
||||
- file
|
||||
level: WARN
|
||||
propagate: 0
|
||||
werkzeug:
|
||||
handlers:
|
||||
- console
|
||||
- normal
|
||||
- file
|
||||
level: INFO
|
||||
propagate: 0
|
||||
root:
|
||||
handlers:
|
||||
- normal
|
||||
- file
|
||||
level: {level}
|
||||
"""
|
||||
|
||||
|
@ -90,10 +86,8 @@ class LogConfig(object):
|
|||
self.ARA_LOG_FILE = ara_config('logfile', 'ARA_LOG_FILE', 'ara.log')
|
||||
self.ARA_LOG_LEVEL = ara_config('loglevel', 'ARA_LOG_LEVEL', 'INFO')
|
||||
if self.ARA_LOG_LEVEL == 'DEBUG':
|
||||
self.SQLALCHEMY_ECHO = True
|
||||
self.ARA_ENABLE_DEBUG_VIEW = True
|
||||
else:
|
||||
self.SQLALCHEMY_ECHO = False
|
||||
self.ARA_ENABLE_DEBUG_VIEW = False
|
||||
|
||||
@property
|
||||
|
@ -131,7 +125,7 @@ def setup_logging(config=None):
|
|||
else:
|
||||
logging.config.fileConfig(config['ARA_LOG_CONFIG'])
|
||||
|
||||
logger = logging.getLogger('ara.logging')
|
||||
logger = logging.getLogger('ara.config.logging')
|
||||
msg = 'Logging: Level {level} from {config}, logging to {dir}/{file}'
|
||||
msg = msg.format(
|
||||
level=config['ARA_LOG_LEVEL'],
|
||||
|
|
|
@ -37,7 +37,7 @@ try:
|
|||
except ImportError:
|
||||
cli = None
|
||||
|
||||
LOG = logging.getLogger('ara.callback')
|
||||
log = logging.getLogger('ara.callback')
|
||||
app = create_app()
|
||||
|
||||
|
||||
|
@ -62,6 +62,7 @@ class CallbackModule(CallbackBase):
|
|||
def __init__(self):
|
||||
super(CallbackModule, self).__init__()
|
||||
|
||||
log.debug('Initializing callback')
|
||||
if not current_app:
|
||||
ctx = app.app_context()
|
||||
ctx.push()
|
||||
|
@ -80,6 +81,7 @@ class CallbackModule(CallbackBase):
|
|||
self._options = cli.options
|
||||
else:
|
||||
self._options = None
|
||||
log.debug('Callback initialized')
|
||||
|
||||
def get_or_create_host(self, hostname):
|
||||
try:
|
||||
|
@ -120,7 +122,7 @@ class CallbackModule(CallbackBase):
|
|||
|
||||
file_.content = content
|
||||
except IOError:
|
||||
LOG.warn('failed to open %s for reading', path)
|
||||
log.warn('failed to open %s for reading', path)
|
||||
|
||||
return file_
|
||||
|
||||
|
@ -130,7 +132,7 @@ class CallbackModule(CallbackBase):
|
|||
host completes. It is responsible for logging a single
|
||||
'TaskResult' record to the database.
|
||||
"""
|
||||
LOG.debug('logging task result for task %s (%s), host %s',
|
||||
log.debug('Logging task result for task %s (%s), host %s',
|
||||
self.task.name, self.task.id, result._host.get_name())
|
||||
|
||||
# An include_role task might end up putting an IncludeRole object
|
||||
|
@ -194,7 +196,7 @@ class CallbackModule(CallbackBase):
|
|||
"""
|
||||
Logs playbook statistics to the database.
|
||||
"""
|
||||
LOG.debug('logging stats')
|
||||
log.debug('logging stats')
|
||||
hosts = sorted(stats.processed.keys())
|
||||
for hostname in hosts:
|
||||
host = self.get_or_create_host(hostname)
|
||||
|
@ -215,7 +217,7 @@ class CallbackModule(CallbackBase):
|
|||
Marks the completion time of the currently active task.
|
||||
"""
|
||||
if self.task is not None:
|
||||
LOG.debug('closing task %s (%s)',
|
||||
log.debug('Closing task %s (%s)',
|
||||
self.task.name,
|
||||
self.task.id)
|
||||
self.task.stop()
|
||||
|
@ -230,7 +232,7 @@ class CallbackModule(CallbackBase):
|
|||
Marks the completion time of the currently active play.
|
||||
"""
|
||||
if self.play is not None:
|
||||
LOG.debug('closing play %s (%s)', self.play.name, self.play.id)
|
||||
log.debug('Closing play %s (%s)', self.play.name, self.play.id)
|
||||
self.play.stop()
|
||||
db.session.add(self.play)
|
||||
db.session.commit()
|
||||
|
@ -242,7 +244,7 @@ class CallbackModule(CallbackBase):
|
|||
Marks the completion time of the currently active playbook.
|
||||
"""
|
||||
if self.playbook is not None:
|
||||
LOG.debug('closing playbook %s', self.playbook.path)
|
||||
log.debug('Closing playbook %s', self.playbook.path)
|
||||
self.playbook.stop()
|
||||
self.playbook.complete = True
|
||||
db.session.add(self.playbook)
|
||||
|
@ -276,7 +278,7 @@ class CallbackModule(CallbackBase):
|
|||
is_handler=False):
|
||||
self.close_task()
|
||||
|
||||
LOG.debug('starting task %s (action %s)',
|
||||
log.debug('Starting task %s (action %s)',
|
||||
task.name, task.action)
|
||||
pathspec = task.get_path()
|
||||
if pathspec:
|
||||
|
@ -319,7 +321,7 @@ class CallbackModule(CallbackBase):
|
|||
msg = "Parameter not saved by ARA due to configuration"
|
||||
options[parameter] = msg
|
||||
|
||||
LOG.debug('starting playbook %s', path)
|
||||
log.debug('Starting playbook %s', path)
|
||||
self.playbook = models.Playbook(
|
||||
ansible_version=ansible_version,
|
||||
path=path,
|
||||
|
@ -340,7 +342,7 @@ class CallbackModule(CallbackBase):
|
|||
self.close_task()
|
||||
self.close_play()
|
||||
|
||||
LOG.debug('starting play %s', play.name)
|
||||
log.debug('Starting play %s', play.name)
|
||||
if self.play is not None:
|
||||
self.play.stop()
|
||||
|
||||
|
@ -361,5 +363,5 @@ class CallbackModule(CallbackBase):
|
|||
self.close_play()
|
||||
self.close_playbook()
|
||||
|
||||
LOG.debug('closing database')
|
||||
log.debug('Closing database')
|
||||
db.session.close()
|
||||
|
|
12
ara/shell.py
12
ara/shell.py
|
@ -15,6 +15,7 @@
|
|||
# You should have received a copy of the GNU General Public License
|
||||
# along with ARA. If not, see <http://www.gnu.org/licenses/>.
|
||||
|
||||
import logging
|
||||
import sys
|
||||
|
||||
from ara import __version__
|
||||
|
@ -24,6 +25,9 @@ from cliff.commandmanager import CommandManager
|
|||
from flask import current_app
|
||||
|
||||
|
||||
log = logging.getLogger('ara.shell')
|
||||
|
||||
|
||||
class AraCli(App):
|
||||
"""
|
||||
A CLI client to query ARA databases
|
||||
|
@ -44,10 +48,10 @@ class AraCli(App):
|
|||
return parser
|
||||
|
||||
def initialize_app(self, argv):
|
||||
self.LOG.debug('initialize_app')
|
||||
log.debug('initialize_app')
|
||||
|
||||
def prepare_to_run_command(self, cmd):
|
||||
self.LOG.debug('prepare_to_run_command %s', cmd.__class__.__name__)
|
||||
log.debug('prepare_to_run_command: %s', cmd.__class__.__name__)
|
||||
|
||||
# Note: cliff uses self.app for itself, this gets folded back into
|
||||
# self.app.ara
|
||||
|
@ -57,9 +61,9 @@ class AraCli(App):
|
|||
self.ara_context.push()
|
||||
|
||||
def clean_up(self, cmd, result, err):
|
||||
self.LOG.debug('clean_up %s', cmd.__class__.__name__)
|
||||
log.debug('clean_up %s', cmd.__class__.__name__)
|
||||
if err:
|
||||
self.LOG.debug('got an error: %s', err)
|
||||
log.debug('got an error: %s', err)
|
||||
|
||||
self.ara_context.pop()
|
||||
|
||||
|
|
|
@ -51,6 +51,7 @@ class TestConfig(TestAra):
|
|||
],
|
||||
'FREEZER_RELATIVE_URLS': True,
|
||||
'SQLALCHEMY_TRACK_MODIFICATIONS': False,
|
||||
'SQLALCHEMY_ECHO': False,
|
||||
'SQLALCHEMY_POOL_SIZE': None,
|
||||
'SQLALCHEMY_POOL_TIMEOUT': None,
|
||||
'SQLALCHEMY_POOL_RECYCLE': None,
|
||||
|
|
|
@ -15,6 +15,8 @@
|
|||
# You should have received a copy of the GNU General Public License
|
||||
# along with ARA. If not, see <http://www.gnu.org/licenses/>.
|
||||
|
||||
import logging
|
||||
|
||||
from ara import models
|
||||
from ara import utils
|
||||
from flask import abort
|
||||
|
@ -28,6 +30,7 @@ from flask import url_for
|
|||
YIELD_PER = 100
|
||||
|
||||
reports = Blueprint('reports', __name__)
|
||||
log = logging.getLogger(__name__)
|
||||
|
||||
|
||||
# This is a flask-frozen workaround in order to generate an index.html
|
||||
|
@ -109,10 +112,12 @@ def ajax_parameters(playbook):
|
|||
results['data'].append(['playbook_path', playbook.path])
|
||||
results['data'].append(['ansible_version', playbook.ansible_version])
|
||||
|
||||
log.debug('Loading playbook parameters')
|
||||
if playbook.options:
|
||||
for option in playbook.options:
|
||||
results['data'].append([option, playbook.options[option]])
|
||||
|
||||
log.debug('%s playbook parameters loaded' % len(results['data']))
|
||||
return jsonify(results)
|
||||
|
||||
|
||||
|
@ -130,6 +135,7 @@ def ajax_plays(playbook):
|
|||
results = dict()
|
||||
results['data'] = list()
|
||||
|
||||
log.debug('Loading plays')
|
||||
for play in plays.yield_per(YIELD_PER):
|
||||
name = u"<span class='pull-left'>{0}</span>".format(play.name)
|
||||
start = date.render(date=play.time_start)
|
||||
|
@ -137,6 +143,7 @@ def ajax_plays(playbook):
|
|||
duration = time.render(time=play.duration)
|
||||
results['data'].append([name, start, end, duration])
|
||||
|
||||
log.debug('%s plays loaded' % len(results['data']))
|
||||
return jsonify(results)
|
||||
|
||||
|
||||
|
@ -154,12 +161,14 @@ def ajax_records(playbook):
|
|||
results = dict()
|
||||
results['data'] = list()
|
||||
|
||||
log.debug('Loading records')
|
||||
for record in records.yield_per(YIELD_PER):
|
||||
key = record_key.render(record=record)
|
||||
value = record_value.render(record=record)
|
||||
|
||||
results['data'].append([key, value])
|
||||
|
||||
log.debug('%s records loaded' % len(results['data']))
|
||||
return jsonify(results)
|
||||
|
||||
|
||||
|
@ -180,6 +189,8 @@ def ajax_results(playbook):
|
|||
results = dict()
|
||||
results['data'] = list()
|
||||
|
||||
log.debug('Loading results')
|
||||
log.debug('* If this part eats your RAM, please help us fix this :)')
|
||||
for result in task_results.yield_per(YIELD_PER):
|
||||
name = name_cell.render(tags=result.task.tags, name=result.task.name)
|
||||
host = result.host.name
|
||||
|
@ -192,6 +203,8 @@ def ajax_results(playbook):
|
|||
derived_status=result.derived_status)
|
||||
|
||||
results['data'].append([name, host, action, elapsed, duration, status])
|
||||
|
||||
log.debug('%s results loaded' % len(results['data']))
|
||||
return jsonify(results)
|
||||
|
||||
|
||||
|
@ -208,6 +221,7 @@ def ajax_stats(playbook):
|
|||
results = dict()
|
||||
results['data'] = list()
|
||||
|
||||
log.debug('Loading host statistics and facts')
|
||||
for stat in stats.yield_per(YIELD_PER):
|
||||
host = host_link.render(host=stat.host)
|
||||
ok = stat.ok if stat.ok >= 1 else 0
|
||||
|
@ -219,4 +233,5 @@ def ajax_stats(playbook):
|
|||
data = [host, ok, changed, failed, skipped, unreachable]
|
||||
results['data'].append(data)
|
||||
|
||||
log.debug('%s host stats and facts loaded' % len(results['data']))
|
||||
return jsonify(results)
|
||||
|
|
|
@ -187,6 +187,9 @@ def configure_template_filters(app):
|
|||
|
||||
|
||||
def configure_context_processors(app):
|
||||
log = logging.getLogger('ara.webapp.context_processors')
|
||||
log.debug('Loading context_processors...')
|
||||
|
||||
@app.context_processor
|
||||
def ctx_add_nav_data():
|
||||
"""
|
||||
|
@ -210,6 +213,9 @@ def configure_context_processors(app):
|
|||
|
||||
|
||||
def configure_blueprints(app):
|
||||
log = logging.getLogger('ara.webapp.configure_blueprints')
|
||||
log.debug('Loading blueprints...')
|
||||
|
||||
import ara.views # flake8: noqa
|
||||
views = (
|
||||
(ara.views.about, '/about'),
|
||||
|
@ -222,7 +228,7 @@ def configure_blueprints(app):
|
|||
for view, prefix in views:
|
||||
app.register_blueprint(view, url_prefix=prefix)
|
||||
|
||||
if app.config.get('ARA_ENABLE_DEBUG_VIEW'):
|
||||
if app.config.get('ARA_LOG_LEVEL') == 'DEBUG':
|
||||
app.register_blueprint(ara.views.debug, url_prefix='/debug')
|
||||
|
||||
|
||||
|
@ -235,7 +241,8 @@ def configure_db(app):
|
|||
revision which contains the latest state of the database prior to this.
|
||||
"""
|
||||
models.db.init_app(app)
|
||||
log = logging.getLogger(app.logger_name)
|
||||
log = logging.getLogger('ara.webapp.configure_db')
|
||||
log.debug('Setting up database...')
|
||||
|
||||
if app.config.get('ARA_AUTOCREATE_DATABASE'):
|
||||
with app.app_context():
|
||||
|
@ -282,6 +289,9 @@ def configure_static_route(app):
|
|||
# dots and we can decorate "serve_static_packaged" instead of, say,
|
||||
# "static.serve_packaged".
|
||||
|
||||
log = logging.getLogger('ara.webapp.configure_static_route')
|
||||
log.debug('Loading static routes...')
|
||||
|
||||
@app.route('/static/packaged/<module>/<path:filename>')
|
||||
def serve_static_packaged(module, filename):
|
||||
xstatic = app.config['XSTATIC']
|
||||
|
@ -294,5 +304,8 @@ def configure_static_route(app):
|
|||
|
||||
def configure_cache(app):
|
||||
""" Sets up an attribute to cache data in the app context """
|
||||
log = logging.getLogger('ara.webapp.configure_cache')
|
||||
log.debug('Configuring cache')
|
||||
|
||||
if not getattr(app, '_cache', None):
|
||||
app._cache = {}
|
||||
|
|
|
@ -125,8 +125,6 @@ Parameters and their defaults
|
|||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| ARA_LOG_FORMAT_ | logformat | %(asctime)s - %(levelname)s - %(message)s |
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| ARA_SQL_DEBUG_ | sqldebug | False |
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| ARA_IGNORE_PARAMETERS_ | ignore_parameters | extra_vars |
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| ARA_IGNORE_EMPTY_GENERATION_ | ignore_empty_generation | True |
|
||||
|
@ -139,6 +137,8 @@ Parameters and their defaults
|
|||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| ARA_RESULT_PER_PAGE_ | result_per_page | 25 |
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| SQLALCHEMY_ECHO_ | sqlalchemy_echo | False |
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| SQLALCHEMY_POOL_SIZE_ | sqlalchemy_pool_size | None (default managed by flask-sqlalchemy)|
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
| SQLALCHEMY_POOL_TIMEOUT_ | sqlalchemy_pool_timeout | None (default managed by flask-sqlalchemy)|
|
||||
|
@ -146,6 +146,7 @@ Parameters and their defaults
|
|||
| SQLALCHEMY_POOL_RECYCLE_ | sqlalchemy_pool_recycle | None (default managed by flask-sqlalchemy)|
|
||||
+-------------------------------+----------------------------+-------------------------------------------+
|
||||
|
||||
.. _SQLALCHEMY_ECHO: http://flask-sqlalchemy.pocoo.org/2.3/config/#configuration-keys
|
||||
.. _SQLALCHEMY_POOL_SIZE: http://flask-sqlalchemy.pocoo.org/2.3/config/#configuration-keys
|
||||
.. _SQLALCHEMY_POOL_TIMEOUT: http://flask-sqlalchemy.pocoo.org/2.3/config/#configuration-keys
|
||||
.. _SQLALCHEMY_POOL_RECYCLE: http://flask-sqlalchemy.pocoo.org/2.3/config/#configuration-keys
|
||||
|
@ -269,11 +270,6 @@ ARA_LOG_FORMAT
|
|||
|
||||
The log format of the logs.
|
||||
|
||||
ARA_SQL_DEBUG
|
||||
~~~~~~~~~~~~~
|
||||
|
||||
Enables the SQLAlchemy echo verbose mode.
|
||||
|
||||
ARA_IGNORE_PARAMETERS
|
||||
~~~~~~~~~~~~~~~~~~~~~
|
||||
|
||||
|
|
Loading…
Reference in New Issue