def release(self):
"""Release service resource."""
self.storage.disconnect()
Cause.reset()
Config.reset()
Logger.reset()
def test_logger_012(logger, caplog, capsys):
"""Test logger security.
Test case verifies that debug configuration is not printing extremely
long log messages. These are prevented for safety and security reasons.
There must be a security event logged.
"""
Logger.configure({
'debug': True,
'log_json': False,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': False
})
logger.debug('variable%s',
('a' * (Logger.SECURITY_LOG_MSG_MAX + 1000)))
out, err = capsys.readouterr()
assert not err
assert len(out.splitlines()) == 2
assert len(caplog.records[:]) == 2
assert 'long log message detected and truncated' in caplog.text
assert 'variableaaaaaaaa' in out
assert len(
max(caplog.text.split(),
key=len)) == len('variable' + 'a' *
Logger.SECURITY_LOG_MSG_MAX) - len('variable')
def test_logger_003(capsys, caplog):
"""Test logger basic usage.
Test case verifies that very verbose option works for text logs.
In this case the length of the log message must be truncated and
the message must be in all lower case characters.
"""
Logger.remove()
Logger.configure({
'debug': False,
'log_json': False,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': True
})
logger = Logger.get_logger('snippy.' + __name__)
logger.warning('abcdefghij' * 100)
logger.warning('VARIABLE %s', ('ABCDEFGHIJ' * 100))
logger.security('SECURITY %s', ('ABCDEFGHIJ' * 100))
out, err = capsys.readouterr()
assert not err
assert 'abcdefghijabcdefg...' in out
assert 'abcdefghijabcdefgh...' in out
assert 'variable abcdefghij' in out
assert len(caplog.records[0].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[1].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[2].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert caplog.records[0].msg.islower()
assert caplog.records[1].msg.islower()
assert caplog.records[2].msg.islower()
def test_logger_005(capsys, caplog):
"""Test logger basic usage.
Test case verifies that very verbose option works with json logs.
"""
Logger.remove()
Logger.configure({
'debug': False,
'log_json': True,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': True
})
logger = Logger.get_logger('snippy.' + __name__)
logger.warning('abcdefghij' * 100)
logger.warning('variable %s', ('abcdefghij' * 100))
out, err = capsys.readouterr()
assert not err
assert len(json.loads(
out.splitlines()[0])['message']) == Logger.DEFAULT_LOG_MSG_MAX
assert len(json.loads(
out.splitlines()[1])['message']) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[0].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[1].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert Field.is_iso8601(json.loads(out.splitlines()[0])['asctime'])
assert Field.is_iso8601(json.loads(out.splitlines()[1])['asctime'])
def test_logger_013(logger, caplog, capsys):
"""Test logger security.
Test case verifies that security log is not printed when log exceeds
the limit with the very verbose ``-vv`` option. This option already
truncates the log and there is no need to ward about long logs.
The log message max length is also reduced in this test.
"""
Logger.configure({
'debug': True,
'log_json': False,
'log_msg_max': 30,
'quiet': False,
'very_verbose': True
})
logger.debug('variable%s',
('a' * (Logger.SECURITY_LOG_MSG_MAX + 1000)))
out, err = capsys.readouterr()
assert not err
assert len(out.splitlines()) == 1
assert len(caplog.records[:]) == 1
assert 'variableaaaaaaaaaaaaaaaaaaa...' in out
def test_logger_014(capsys, caplog):
"""Test custom security level.
Test case verifies that the custom ``security`` level is working.
"""
Logger.remove()
Logger.configure({
'debug': False,
'log_json': False,
'log_msg_max': 120,
'quiet': False,
'very_verbose': True
})
logger = Logger.get_logger('snippy.' + __name__)
logger.security('SECURITY %s', ('ABCDEFGHIJ' * 100))
out, err = capsys.readouterr()
assert not err
assert 'security abcdefghij' in out
assert len(caplog.records[0].msg) == 120
assert caplog.records[0].appname == 'snippy'
assert caplog.records[0].levelname == 'security'
assert caplog.records[0].levelno == Logger.SECURITY
assert hasattr(caplog.records[0], 'oid')
def on_exit(server):
"""Gunicorn server exit hook.
This is used to tell user that the server has been stopped.
Args:
server (obj): Gunicorn Arbiter() class object.
"""
Logger.print_status('snippy server stopped at: {}'.format(server.app.options['snippy_host']))
def _ssl_file(cls, filename):
"""Test that given SSL/TLS certificate or key file exist."""
if filename is not None and not os.path.isfile(filename):
Logger.print_status(
'NOK: cannot run secured server because ssl/tls certificate file cannot be read: {}'
.format(filename))
sys.exit(1)
return filename
def merge(self, source):
"""Merge a resource to collection.
Merge content into existing resource or create new content. Returns
the message digest after merging the content.
If content source does not exist in the collection it causes migrage
operation.
This method cannot merge a collection because so far there has been
no need for it.
Args:
source (Resource): Resource to be merged to collection.
Returns:
str: None or message digest after merging the source.
"""
digest = None
if not source or not isinstance(source, Resource):
self._logger.debug(
'source was not merged to collection: {}'.format(
Logger.remove_ansi(str(source))))
return digest
if source.digest in self.keys():
if self[source.digest].merge(source):
digest = self[source.digest].digest
else:
self._logger.debug(
'merging content to existing resource failed: {}'.format(
Logger.remove_ansi(str(source))))
try:
del self[source.digest]
except KeyError:
self._logger.info(
'unexpected failure to delete existing content: {}'.
format(Logger.remove_ansi(str(source))))
else:
if self.migrate(source):
digest = source.digest
else:
self._logger.debug(
'migrating new content to collection failed: {}'.format(
Logger.remove_ansi(str(source))))
try:
del self[
source.
digest] # This should never be executed. But just in case of an error in above migrate method.
except KeyError:
pass
return digest
def post_worker_init(worker):
"""Gunicorn worker initialized hook.
This is called by the Gunicorn framework after a worker has been
initialized. This is used to tell user that the server is running.
Gunicorn server listen IP address is printed from workber because
of a use where a random free ephemeral port is selected by OS.
Args:
worker (obj): Gunicorn Worker() class object.
"""
listeners = ','.join([str(l) for l in worker.sockets])
Logger.print_status('snippy server running at: {}'.format(listeners))
def _update_logger(cls):
"""Update logger configuration."""
Logger.configure({
'debug': cls.debug_logs,
'log_json': cls.log_json,
'log_msg_max': cls.log_msg_max,
'quiet': cls.quiet,
'very_verbose': cls.very_verbose
})
cls._logger.debug(
'config log settings debug: {} :very verbose: {} :quiet: {} :json logs: {} :log msg max: {}'
.format(cls.debug_logs, cls.very_verbose, cls.quiet, cls.log_json,
cls.log_msg_max))
def _set_integrity_error(self, error, resource):
"""Set integrity error.
Args:
error (Exception): Exception string from integrity error.
resource (Resource): Resource which SQL operation caused exception.
"""
digest = self._get_digest(resource)
match = self._catch_violating_column.search(str(error))
if match:
if match.group('column') == 'uuid' and not Config.defaults:
cause = Cause.HTTP_500
else:
cause = Cause.HTTP_CONFLICT
Cause.push(
cause, 'content: {} :already exist with digest: {:.16}'.format(
match.group('column'), digest))
else:
self._logger.info(
'database integrity error parse failure: {}'.format(error))
Cause.push(
Cause.HTTP_CONFLICT,
'content already exist with digest: {:.16}'.format(digest))
if not Config.defaults:
self._logger.info(
'database integrity error from database: {}'.format(
traceback.format_exc()))
self._logger.info(
'database integrity error from resource: {}'.format(
Logger.remove_ansi(str(resource))))
self._logger.info(
'database integrity error stack trace: {}'.format(
traceback.format_stack(limit=20)))
def server_schema_base_uri(cls):
"""Get server API schema base URI.
Returns:
str: Path where the API schema is stored in URI format.
"""
filepath = pkg_resources.resource_filename(
'snippy', 'data/server/openapi/schema/')
if not os.path.isdir(filepath):
Logger.print_status(
'NOK: cannot run because server api schema base uri is not accessible: {}'
.format(filepath))
sys.exit(1)
return 'file:' + filepath
def __init__(self, category='', timestamp='', list_=None, dict_=None):
self._logger = Logger.get_logger(__name__)
self._id = ''
self._category = category
self._data = ()
self._brief = ''
self._description = ''
self._name = ''
self._groups = Const.DEFAULT_GROUPS
self._tags = ()
self._links = ()
self._source = ''
self._versions = ()
self._filename = ''
self._created = timestamp
self._updated = timestamp
self._uuid = ''
self._digest = ''
if list_ or dict_:
self.convert(list_, dict_)
if not self._id:
self._id = self._get_internal_uuid()
if not self._uuid:
self._uuid = self._get_external_uuid()
self._digest = self._compute_digest()
def __init__(self, storage, category, run_cli):
self._logger = Logger.get_logger(__name__)
self._category = category
self._run_cli = run_cli
self._storage = storage
self._collection = None
self._uniques = ()
def migrate(self, source):
"""Migrate resource or collection to collection.
Add new resources or override originals if they exist.
Args:
source (content): Resource or Collection that is migrated.
"""
migrated = False
if isinstance(source, Collection):
for resource in source.resources():
self.migrate(resource)
elif isinstance(source, Resource):
if source.category in Const.CATEGORIES:
if source.seal():
if source.digest not in self.keys():
self._data['meta'][
'total'] = self._data['meta']['total'] + 1
self._data['data'][source.digest] = {}
self._data['data'][source.digest]['data'] = source
migrated = True
else:
self._logger.debug(
'resource: {} :not migrated to collection'.format(
source.digest))
else:
self._logger.debug(
'migrate to collection failed due to unknown category: {}'.
format(Logger.remove_ansi(str(source))))
return migrated
def __init__(self):
self._logger = Logger.get_logger(__name__)
self._db = Const.DB_SQLITE
self._connection = None
self._columns = ()
self._regexp = 'REGEXP'
self._placeholder = '?'
self._catch_violating_column = self.RE_CATCH_UNIQUE_SQLITE_COLUMN
def dump_term(self, templates, template_format, use_ansi, debug_logs):
"""Convert collection for terminal.
Args:
templates (dict): Dictionary that contains content templates.
template_format (str): Define the output format
use_ansi (bool): Define if ANSI characters are used.
debug_logs (bool): Define if debut information is included.
"""
text = Const.EMPTY
if template_format == Const.CONTENT_FORMAT_MKDN:
text = self.dump_mkdn(templates)
else:
text = self._dump_term(use_ansi, debug_logs)
self._logger.debug('printing content to terminal stdout')
Logger.print_stdout(text)
def logger_wrapper(request):
"""Create logger."""
from snippy.logger import Logger
# Previous test may have configured the logger and therefore
# the logger must be always reset before test.
Logger.reset()
logger = Logger.get_logger('snippy.' + __name__)
def fin():
"""Clear the resources at the end."""
Logger.remove()
request.addfinalizer(fin)
return logger
def test_logger_002(logger, caplog, capsys):
"""Test logger basic usage.
Test case verifies that debug configuration is working. In
this case the debug level should be applied that must produce
full length lines from all log levels.
"""
Logger.configure({
'debug': True,
'log_json': False,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': False
})
# Test log levels.
logger.security('testing security level')
logger.critical('testing critical level')
logger.error('testing error level')
logger.warning('testing warning level')
logger.info('testing info level')
logger.debug('testing debug level')
# Test log message length.
logger.warning('abcdefghij' * 100)
out, err = capsys.readouterr()
assert not err
assert len(out.splitlines()) == 7
assert 'testing critical level' in out
assert 'testing error level' in out
assert 'testing warning level' in out
assert 'testing info level' in out
assert 'testing debug level' in out
assert len(caplog.records[:]) == 7
assert 'testing critical level' in caplog.text
assert 'testing error level' in caplog.text
assert 'testing warning level' in caplog.text
assert 'testing info level' in caplog.text
assert 'testing debug level' in caplog.text
assert max(caplog.text.split(), key=len) == 'abcdefghij' * 100
with pytest.raises(Exception):
json.loads(out)
def _test_resource(path, filename):
"""Test if Snippy resource exists.
Args:
path (str): Relative path under the snippy project.
filename (str): Resource filename.
Returns:
str: File if the resource exists.
"""
filename = os.path.join(
pkg_resources.resource_filename('snippy', path), filename)
if not os.path.isfile(filename):
Logger.print_status(
'NOK: cannot run because snippy resource file is not accessible: {}'
.format(filename))
sys.exit(1)
return filename
def test_logger_016(capsys):
"""Test logs from Gunicorn.
Test case verifies that log log messages from Gunicorn are converted
correctly to Snippy server logs. The informative logs from Gunicorn
must be converted to debug level logs. All other log level must be
kept the same.
"""
Logger.remove()
Logger.configure({
'debug': True,
'log_json': True,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': False
})
logger = Logger.get_logger('snippy.server.gunicorn')
# Test log levels.
logger.security('testing security level')
logger.critical('testing critical level')
logger.error('testing error level')
logger.warning('testing warning level')
logger.info('testing info level')
logger.debug('testing debug level')
out, err = capsys.readouterr()
assert not err
assert json.loads(out.splitlines()[0])['levelno'] == 60
assert json.loads(out.splitlines()[0])['levelname'] == 'security'
assert json.loads(out.splitlines()[1])['levelno'] == 50
assert json.loads(out.splitlines()[1])['levelname'] == 'crit'
assert json.loads(out.splitlines()[2])['levelno'] == 40
assert json.loads(out.splitlines()[2])['levelname'] == 'err'
assert json.loads(out.splitlines()[3])['levelno'] == 30
assert json.loads(out.splitlines()[3])['levelname'] == 'warning'
assert json.loads(out.splitlines()[4])['levelno'] == 10
assert json.loads(out.splitlines()[4])['levelname'] == 'debug'
assert json.loads(out.splitlines()[5])['levelno'] == 10
assert json.loads(out.splitlines()[5])['levelname'] == 'debug'
def __init__(self, timestamp, dictionary, collection):
"""
Args:
timestamp (str): IS8601 timestamp used with created resources.
dictionary (dict): Dictionary where the content is read.
collection (Collection()): Collection where the content is stored.
"""
self._logger = Logger.get_logger(__name__)
self._timestamp = timestamp
self._dictionary = dictionary
self._collection = collection
def __init__(self, timestamp, text, collection):
"""
Args:
timestamp (str): IS8601 timestamp used with created resources.
text (str): Source text that is parsed.
collection (Collection()): Collection where the content is stored.
"""
self._logger = Logger.get_logger(__name__)
self._timestamp = timestamp
self._text = text
self._collection = collection
def _storage_file(cls):
"""Construct store file with absolute path.
The in-memory database is supported only in Python 3. The Sqlite, which
is used as a in-memory database, supports this feature only in Python 3.
Returns:
str: Path or URI to the storage.
"""
if cls.source.run_healthcheck:
return Const.EMPTY
if Config.storage_type == Const.DB_IN_MEMORY and not Const.PYTHON2:
return 'file::memory:?cache=shared'
if Config.storage_path:
storage_path = Config.storage_path
else:
storage_path = pkg_resources.resource_filename(
'snippy', 'data/storage')
if os.path.exists(storage_path) and os.access(storage_path, os.W_OK):
storage_file = os.path.join(storage_path, 'snippy.db')
elif cls.source.server_readonly and os.path.exists(
storage_path) and os.access(storage_path, os.R_OK):
cls._logger.debug('running server in readonly mode')
storage_file = os.path.join(storage_path, 'snippy.db')
else:
# This is a special case which prevents additional error log after
# tool is already about to exit with help text from the CLI parser.
if not cls.source.failure:
Logger.print_status(
'NOK: cannot run because content storage path is not writable: {}'
.format(storage_path))
sys.exit(1)
return storage_file
def test_logger_015(capsys, caplog):
"""Test failure handling.
Test case verifies that log message length cannot exceed safety limits
that are defined for a security reasons. Because the very verbose mode
is used, the log messages are limited to default length.
"""
Logger.remove()
Logger.configure({
'debug': False,
'log_json': False,
'log_msg_max':
Logger.SECURITY_LOG_MSG_MAX + Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': True
})
logger = Logger.get_logger('snippy.' + __name__)
logger.warning('abcdefghij' * 100)
logger.warning('VARIABLE %s', ('ABCDEFGHIJ' * 100))
logger.security('SECURITY %s', ('ABCDEFGHIJ' * 100))
out, err = capsys.readouterr()
assert not err
assert 'abcdefghijabcdefg...' in out
assert 'abcdefghijabcdefgh...' in out
assert 'variable abcdefghij' in out
assert 'log message length: 10080 :cannot exceed security limit: 10000' in caplog.text
assert len(caplog.records[1].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[2].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[3].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert caplog.records[0].msg.islower()
assert caplog.records[1].msg.islower()
assert caplog.records[2].msg.islower()
assert caplog.records[3].msg.islower()
def __init__(self, filetype, timestamp, source, collection):
"""
Args:
filetype (str): Filetype that defines used parser.
timestamp (str): IS8601 timestamp used with created resources.
source (str|dict): Source text or dictionary that is parsed.
collection (Collection): Collection object where content is stored.
"""
self._logger = Logger.get_logger(__name__)
self._filetype = filetype
self._timestamp = timestamp
self._source = source
self._collection = collection
self._parser = self._parser_factory()
def test_logger_011(capsys, caplog):
"""Test logger advanced configuration.
Test case verifies that log maximum message length can be configred
and that the configuration can be changed. The case also tests that
static logger fields are not changed when logger is reconfigured.
"""
Logger.remove()
Logger.configure({
'debug': False,
'log_json': False,
'log_msg_max': 120,
'quiet': False,
'very_verbose': True
})
logger = Logger.get_logger('snippy.' + __name__)
logger.warning('abcdefghij' * 100)
logger.warning('VARIABLE %s', ('ABCDEFGHIJ' * 100))
out, err = capsys.readouterr()
assert not err
assert 'abcdefghijabcdefg...' in out
assert 'abcdefghijabcdefgh...' in out
assert 'variable abcdefghij' in out
assert len(caplog.records[0].msg) == 120
assert len(caplog.records[1].msg) == 120
assert caplog.records[0].appname == 'snippy'
assert caplog.records[1].appname == 'snippy'
caplog.clear()
Logger.configure({
'debug': False,
'log_json': True,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': True
})
logger.warning('abcdefghij' * 100)
logger.warning('VARIABLE %s', ('ABCDEFGHIJ' * 100))
out, err = capsys.readouterr()
assert not err
assert 'abcdefghijabcdefg...' in out
assert 'abcdefghijabcdefgh...' in out
assert 'variable abcdefghij' in out
assert len(caplog.records[0].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert len(caplog.records[1].msg) == Logger.DEFAULT_LOG_MSG_MAX
assert caplog.records[0].appname == 'snippy'
assert caplog.records[1].appname == 'snippy'
def test_logger_010(capsys):
"""Test removing snippy Logger handlers.
Test case verifies that Logger.remove() does not delete other than
snippy packages logging handlers.
"""
Logger.remove()
Logger.configure({
'debug': True,
'log_json': True,
'log_msg_max': Logger.DEFAULT_LOG_MSG_MAX,
'quiet': False,
'very_verbose': False
})
_ = Logger.get_logger('other.package')
Logger.remove() # Part of the test.
Logger.debug() # Part of the test.
out, err = capsys.readouterr()
assert not err
assert 'Handler Stream' in out
def __init__(self, derived):
self._logger = Logger.get_logger(__name__)
self._logger.debug('config source: {}'.format(derived))
self._derived = derived
self._reset_fields = {}
self._repr = self._get_repr()
self.complete = Const.EMPTY
self.debug = False
self.defaults = False
self.digest = None
self.editor = False
self.failure = False
self.failure_message = Const.EMPTY
self.template_format = Const.CONTENT_FORMAT_MKDN
self.template_format_used = False
self.languages = ()
self.log_json = False
self.log_msg_max = self.DEFAULT_LOG_MSG_MAX
self.merge = False
self.no_ansi = False
self.no_editor = False
self.operation = None
self.operation_file = Const.EMPTY
self.profiler = False
self.quiet = False
self.run_healthcheck = False
self.server_minify_json = False
self.server_readonly = False
self.server_ssl_ca_cert = None
self.server_ssl_cert = None
self.server_ssl_key = None
self.storage_path = Const.EMPTY
self.storage_type = Const.DB_SQLITE
self.storage_host = Const.EMPTY
self.storage_user = Const.EMPTY
self.storage_password = Const.EMPTY
self.storage_database = Const.EMPTY
self.storage_ssl_cert = None
self.storage_ssl_key = None
self.storage_ssl_ca_cert = None
self.template = False
self.uuid = None
self.version = __version__
self.very_verbose = False
