Name | Description
-----------------------|--------------
TIMET | Current UNIX timestamp.
- LONGDATETIME | Current date and time including timezone information. Example: `2014-01-0311:23:08+0000`
- SHORTDATETIME | Current date and time. Example: `2014-01-0311:23:08`
+ LONGDATETIME | Current date and time including timezone information. Example: `2014-01-03 11:23:08 +0000`
+ SHORTDATETIME | Current date and time. Example: `2014-01-03 11:23:08`
DATE | Current date. Example: `2014-01-03`
- TIME | Current time including timezone information. Example: `11:23:08+0000`
+ TIME | Current time including timezone information. Example: `11:23:08 +0000`
### <a id="runtime-macros-env-vars"></a> Runtime Macros as Environment Variables
"""
-def success(msg):
- print '[OK] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
-def fail(msg):
- print '[FAIL] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
def main():
run_query = lambda q: utils.run_mysql_query(q, b'/usr/bin/mysql')
"where c.display_name = 'PassiveService1'"
state_time = float(next(iter(run_query(query)), {}).get('last_check', '0'))
if state_time == 0:
- fail('"PassiveService1" seems not to have been checked yet')
+ utils.Logger.fail('"PassiveService1" seems not'
+ ' to have been checked yet\n')
return 1
if (state_time + CHECK_INTERVAL) - time.time() < 30:
time.sleep(45)
# Now pass the checkresult in
- with open(os.path.join(CHECKRESULT_LOCATION, 'cfoobar'), 'w') as f:
+ resultfile_path = os.path.join(CHECKRESULT_LOCATION, 'cfoobar')
+ with open(resultfile_path, 'w') as f:
f.write(CHECKRESULT_TEMPLATE % {
'hostname': 'nsca-ng',
'servicename': 'PassiveService1',
'output': 'Passing in CheckResult header files works!'
})
+ utils.Logger.debug('Written file: {0}\n'.format(resultfile_path))
+
# And notfiy Icinga that the file has been completely written...
- with open(os.path.join(CHECKRESULT_LOCATION, 'cfoobar.ok'), 'w') as f:
+ resultfileok_path = os.path.join(CHECKRESULT_LOCATION, 'cfoobar.ok')
+ with open(resultfileok_path, 'w') as f:
pass
+ utils.Logger.debug('Written file: {0}\n'.format(resultfileok_path))
+
# Lastly check whether the service changed its state
time.sleep(CHECKRESULT_READ_INTERVAL * 2)
"where c.display_name = 'PassiveService1'"
output = next(iter(run_query(query)), {}).get('output', '')
if output != 'Passing in CheckResult header files works!':
- fail('Checkresult header files seem not to be processed properly')
+ utils.Logger.fail('Checkresult header files seem '
+ 'not to be processed properly\n')
return 1
- success('Checkresult header files are processed properly')
+ utils.Logger.ok('Checkresult header files are processed properly\n')
return 0
return STATE_MAP.get(value, value)
-def success(msg):
- print '[OK] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
-def fail(msg):
- print '[FAIL] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
-def info(msg):
- print '[INFO] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
-def error(msg):
- print '[ERROR] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
+def validate_time_format(inputstr, formatstr):
+ try:
+ time.strptime(inputstr, formatstr)
+ except ValueError:
+ return False
+ else:
+ return True
def main():
host_info = get_one('GET hosts\nFilter: name = localhost'
'\nColumns: event_handler')
if host_info.get('event_handler') != 'test_event':
- fail('Could not assign eventcommand "test_event" to host "localhost"')
+ utils.Logger.fail('Could not assign eventcommand "test_event"'
+ ' to host "localhost"\n')
return 1
- success('Successfully assigned an eventcommand to host "localhost"')
+ utils.Logger.ok('Successfully assigned an eventcommand'
+ ' to host "localhost"\n')
send_command('PROCESS_HOST_CHECK_RESULT;localhost;1;A negative result to'
' trigger an eventhandler|some interesting perfdata!')
event_output = get_event_output()
if not event_output:
send_command('CHANGE_HOST_EVENT_HANDLER;localhost;')
- fail('Could not trigger the eventcommand')
+ utils.Logger.fail('Could not trigger the eventcommand\n')
return 1
- success('Successfully triggered the eventcommand')
+ utils.Logger.ok('Successfully triggered the eventcommand\n')
failure = False
- info('Checking host macros...')
+ utils.Logger.info('Checking host macros...\n')
host_info = get_one('GET hosts\nFilter: name = localhost\nColumns: {0}'
''.format(' '.join(c for c in LS_HOST_COLUMNS if c)))
if event_output[0] != host_info['name']*2:
failure = True
- fail('Escaping environment variables seems not to properly working')
- fail(' Expected: {0!r} Got: {1!r}'.format(host_info['name']*2,
- event_output[0]))
+ utils.Logger.fail('Escaping environment variables '
+ 'seems not to properly working\n')
+ utils.Logger.fail(' Expected: {0!r} Got: {1!r}\n'
+ ''.format(host_info['name']*2, event_output[0]))
+ else:
+ utils.Logger.ok('Escaped environment variables'
+ ' are properly processed\n')
for i, column in enumerate(LS_HOST_COLUMNS[1:], 1):
if column is not None:
- output_value = convert_output(event_output[i])
+ macro_name, _, macro_value = event_output[i].partition('=')
+ output_value = convert_output(macro_value)
if output_value != host_info[column]:
failure = True
- fail('{0!r} is unequal to {1!r} ({2})'.format(output_value,
- host_info[column],
- column))
-
- info('Checking service macros...')
+ utils.Logger.fail('Macro "{0}" returns an incorrect value. '
+ 'Expected "{2}" but got "{1}"\n'
+ ''.format(macro_name, output_value,
+ host_info[column]))
+ else:
+ utils.Logger.ok('Macro "{0}" returns the correct value\n'
+ ''.format(macro_name))
+
+ utils.Logger.info('Checking service macros...\n')
svc_info = get_one('GET services\nFilter: description = ping4\nColumns: {0}'
''.format(' '.join(c for c in LS_SVC_COLUMNS if c)))
for i, column in enumerate(LS_SVC_COLUMNS, len(LS_HOST_COLUMNS)):
if column is not None:
- output_value = convert_output(event_output[i])
+ macro_name, _, macro_value = event_output[i].partition('=')
+ output_value = convert_output(macro_value)
if output_value != svc_info[column]:
failure = True
- fail('{0!r} is unequal to {1!r} ({2})'.format(output_value,
- svc_info[column],
- column))
-
- info('Checking global macros...')
+ utils.Logger.fail('Macro "{0}" returns an incorrect value. '
+ 'Expected "{2}" but got "{1}"\n'
+ ''.format(macro_name, output_value,
+ svc_info[column]))
+ else:
+ utils.Logger.ok('Macro "{0}" returns the correct value\n'
+ ''.format(macro_name))
+
+ utils.Logger.info('Checking global macros...\n')
+ timet = convert_output(event_output[-6].partition('=')[2])
+ if not isinstance(timet, int):
+ failure = True
+ utils.Logger.fail('Macro "TIMET" does not return a timestamp. '
+ 'Expected int but got: {0!r}\n'.format(timet))
+ else:
+ utils.Logger.ok('Macro "TIMET" returns the correct value\n')
+ longdatetime = event_output[-5].partition('=')[2]
+ longdatetime_format = '%Y-%m-%d %H:%M:%S +0000'
+ if not validate_time_format(longdatetime, longdatetime_format):
+ failure = True
+ utils.Logger.fail('Macro "LONGDATETIME" returns an incorrect value.'
+ ' Expected value of format "{0}" but got "{1}"\n'
+ ''.format(longdatetime_format, longdatetime))
+ else:
+ utils.Logger.ok('Macro "LONGDATETIME" returns the correct value\n')
+ shortdatetime = event_output[-4].partition('=')[2]
+ shortdatetime_format = '%Y-%m-%d %H:%M:%S'
+ if not validate_time_format(shortdatetime, shortdatetime_format):
+ failure = True
+ utils.Logger.fail('Macro "SHORTDATETIME" returns an incorrect value.'
+ ' Expected value of format "{0}" but got "{1}"\n'
+ ''.format(shortdatetime_format, shortdatetime))
+ else:
+ utils.Logger.ok('Macro "SHORTDATETIME" returns the correct value\n')
+ m_date = event_output[-3].partition('=')[2]
+ m_date_format = '%Y-%m-%d'
+ if not validate_time_format(m_date, m_date_format):
+ failure = True
+ utils.Logger.fail('Macro "DATE" returns an incorrect value. '
+ 'Expected value of format "{0}" but got "{1}"\n'
+ ''.format(m_date_format, m_date))
+ else:
+ utils.Logger.ok('Macro "DATE" returns the correct value\n')
+ m_time = event_output[-2].partition('=')[2]
+ m_time_format = '%H:%M:%S +0000'
+ if not validate_time_format(m_time, m_time_format):
+ failure = True
+ utils.Logger.fail('Macro "TIME" returns an incorrect value. '
+ 'Expected value of format "{0}" but got "{1}"\n'
+ ''.format(m_time_format, m_time))
+ else:
+ utils.Logger.ok('Macro "TIME" returns the correct value\n')
- info('Checking command macros...')
- if convert_output(event_output[-1]) != 1337:
+ utils.Logger.info('Checking command macros...\n')
+ if convert_output(event_output[-1].partition('=')[2]) != 1337:
failure = True
- fail('The command macro "custom_macro" is not being substituted')
+ utils.Logger.fail('The command macro "custom_macro"'
+ ' is not being substituted\n')
+ else:
+ utils.Logger.ok('The command macro "custom_macro"'
+ ' is correctly substituted\n')
send_command('DISABLE_HOST_EVENT_HANDLER;localhost')
send_command('PROCESS_HOST_CHECK_RESULT;localhost;0;A positive result that'
' should not trigger an eventhandler')
if get_event_output():
failure = True
- fail('Could not disable the eventcommand')
+ utils.Logger.fail('Could not disable the eventcommand\n')
else:
- success('Successfully disabled the eventcommand')
+ utils.Logger.ok('Successfully disabled the eventcommand\n')
send_command('ENABLE_HOST_EVENT_HANDLER;localhost')
host_info = get_one('GET hosts\nFilter: name = localhost'
'\nColumns: event_handler_enabled')
if host_info['event_handler_enabled'] != 1:
failure = True
- fail('Could not re-enable the eventcommand')
+ utils.Logger.fail('Could not re-enable the eventcommand\n')
else:
- success('Successfully re-enabled the eventcommand')
+ utils.Logger.ok('Successfully re-enabled the eventcommand\n')
send_command('CHANGE_HOST_EVENT_HANDLER;localhost;')
host_info = get_one('GET hosts\nFilter: name = localhost'
'\nColumns: event_handler')
if host_info['event_handler']:
failure = True
- fail('Could not remove eventcommand "test_event"'
- ' assigned to host "localhost"')
+ utils.Logger.fail('Could not remove eventcommand "test_event"'
+ ' assigned to host "localhost"\n')
else:
- success('Successfully removed the eventcommand'
- ' assigned to host "localhost"')
+ utils.Logger.ok('Successfully removed the eventcommand'
+ ' assigned to host "localhost"\n')
return 1 if failure else 0
with utils.LiveStatusSocket(LIVESTATUS_PATH) as LIVESTATUS:
sys.exit(main())
except (OSError, IOError, socket.error), e:
- error('Could not connect to Livestatus socket: {0} ({1})'
- ''.format(LIVESTATUS_PATH, unicode(e)))
+ utils.Logger.error('Could not connect to Livestatus socket: {0} ({1})'
+ '\n'.format(LIVESTATUS_PATH, unicode(e)))
def success(msg):
- print '[OK] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
+ utils.Logger.ok(msg + '\n')
return False
def fail(msg):
- print '[FAIL] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
+ utils.Logger.fail(msg + '\n')
return True
def error(msg):
- print '[ERROR] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
+ utils.Logger.error(msg + '\n')
return True
object EventCommand "test_event" inherits "plugin-event-command" {
command = {{{echo "\
$$HOSTNAME$HOSTNAME$\
-|$HOSTNAME$\
-|$HOSTDISPLAYNAME$\
-|$HOSTALIAS$\
-|$HOSTSTATE$\
-|$HOSTSTATEID$\
-|$HOSTSTATETYPE$\
-|$HOSTATTEMPT$\
-|$MAXHOSTATTEMPT$\
-|$LASTHOSTSTATE$\
-|$LASTHOSTSTATEID$\
-|$LASTHOSTSTATETYPE$\
-|$LASTHOSTSTATECHANGE$\
-|$HOSTDURATIONSEC$\
-|$HOSTLATENCY$\
-|$HOSTEXECUTIONTIME$\
-|$HOSTOUTPUT$\
-|$HOSTPERFDATA$\
-|$LASTHOSTCHECK$\
-|$HOSTADDRESS$\
-|$HOSTADDRESS6$\
-|$SERVICEDESC$\
-|$SERVICEDISPLAYNAME$\
-|$SERVICECHECKCOMMAND$\
-|$SERVICESTATE$\
-|$SERVICESTATEID$\
-|$SERVICESTATETYPE$\
-|$SERVICEATTEMPT$\
-|$MAXSERVICEATTEMPT$\
-|$LASTSERVICESTATE$\
-|$LASTSERVICESTATEID$\
-|$LASTSERVICESTATETYPE$\
-|$LASTSERVICESTATECHANGE$\
-|$SERVICEDURATIONSEC$\
-|$SERVICELATENCY$\
-|$SERVICEEXECUTIONTIME$\
-|$SERVICEOUTPUT$\
-|$SERVICEPERFDATA$\
-|$LASTSERVICECHECK$\
-|$TOTALHOSTSERVICES$\
-|$TOTALHOSTSERVICESOK$\
-|$TOTALHOSTSERVICESWARNING$\
-|$TOTALHOSTSERVICESUNKNOWN$\
-|$TOTALHOSTSERVICESCRITICAL$\
-|$TIMET$\
-|$LONGDATETIME$\
-|$SHORTDATETIME$\
-|$DATE$\
-|$TIME$\
-|$custom_macro$\
+|HOSTNAME=$HOSTNAME$\
+|HOSTDISPLAYNAME=$HOSTDISPLAYNAME$\
+|HOSTALIAS=$HOSTALIAS$\
+|HOSTSTATE=$HOSTSTATE$\
+|HOSTSTATEID=$HOSTSTATEID$\
+|HOSTSTATETYPE=$HOSTSTATETYPE$\
+|HOSTATTEMPT=$HOSTATTEMPT$\
+|MAXHOSTATTEMPT=$MAXHOSTATTEMPT$\
+|LASTHOSTSTATE=$LASTHOSTSTATE$\
+|LASTEHOSTSTATEID=$LASTHOSTSTATEID$\
+|LASTHOSTSTATETYPE=$LASTHOSTSTATETYPE$\
+|LASTHOSTSTATECHANGE=$LASTHOSTSTATECHANGE$\
+|HOSTDURATIONSEC=$HOSTDURATIONSEC$\
+|HOSTLATENCY=$HOSTLATENCY$\
+|HOSTEXECUTIONTIME=$HOSTEXECUTIONTIME$\
+|HOSTOUTPUT=$HOSTOUTPUT$\
+|HOSTPERFDATA=$HOSTPERFDATA$\
+|LASTHOSTCHECK=$LASTHOSTCHECK$\
+|HOSTADDRESS=$HOSTADDRESS$\
+|HOSTADDRESS6=$HOSTADDRESS6$\
+|SERVICEDESC=$SERVICEDESC$\
+|SERVICEDISPLAYNAME=$SERVICEDISPLAYNAME$\
+|SERVICECHECKCOMMAND=$SERVICECHECKCOMMAND$\
+|SERVICESTATE=$SERVICESTATE$\
+|SERVICESTATEID=$SERVICESTATEID$\
+|SERVICESTATETYPE=$SERVICESTATETYPE$\
+|SERVICEATTEMPT=$SERVICEATTEMPT$\
+|MAXSERVICEATTEMPT=$MAXSERVICEATTEMPT$\
+|LASTSERVICESTATE=$LASTSERVICESTATE$\
+|LASTSERVICESTATEID=$LASTSERVICESTATEID$\
+|LASTSERVICESTATETYPE=$LASTSERVICESTATETYPE$\
+|LASTSERVICESTATECHANGE=$LASTSERVICESTATECHANGE$\
+|SERVICEDURATIONSEC=$SERVICEDURATIONSEC$\
+|SERVICELATENCY=$SERVICELATENCY$\
+|SERVICEEXECUTIONTIME=$SERVICEEXECUTIONTIME$\
+|SERVICEOUTPUT=$SERVICEOUTPUT$\
+|SERVICEPERFDATA=$SERVICEPERFDATA$\
+|LASTSERVICECHECK=$LASTSERVICECHECK$\
+|TOTALHOSTSERVICES=$TOTALHOSTSERVICES$\
+|TOTALHOSTSERVICESOK=$TOTALHOSTSERVICESOK$\
+|TOTALHOSTSERVICESWARNING=$TOTALHOSTSERVICESWARNING$\
+|TOTALHOSTSERVICESUNKNOWN=$TOTALHOSTSERVICESUNKNOWN$\
+|TOTALHOSTSERVICESCRITICAL=$TOTALHOSTSERVICESCRITICAL$\
+|TIMET=$TIMET$\
+|LONGDATETIME=$LONGDATETIME$\
+|SHORTDATETIME=$SHORTDATETIME$\
+|DATE=$DATE$\
+|TIME=$TIME$\
+|custom_macro=$custom_macro$\
" > /tmp/test_event.out}}},
export_macros = ["HOSTNAME"],
import sys
from datetime import datetime, timedelta
-CHECK_INTERVAL = 10 # minutes; The actual interval are 5 minutes but as other
+import utils
+
+CHECK_INTERVAL = 10 # minutes; The actual interval is 5 minutes but as other
# tests might restart Icinga we need to take any
# rescheduling into account
}
-def success(msg):
- print '[OK] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
- return True
-
-
-def fail(msg):
- print '[FAIL] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
- return False
-
-
-def info(msg):
- print '[INFO] {0}'.format(msg).encode('utf-8')
- sys.stdout.flush()
-
-
def validate_tables(tables):
"""
Return whether all tables of the IDO database scheme exist in
the given table listing
"""
- info('Checking database scheme... (tables)')
+ utils.Logger.info('Checking database scheme... (tables)\n')
failures = False
for table in (TABLE_PREFIX + n for n in TABLES):
if table in tables:
- success('Found table "{0}" in database'.format(table))
+ utils.Logger.ok('Found table "{0}" in database\n'.format(table))
else:
- fail('Could not find table "{0}" in database'.format(table))
+ utils.Logger.fail('Could not find table "{0}" in database\n'
+ ''.format(table))
failures = True
return not failures
Return whether the example hosts exist in the given "hosts" table
"""
- info('Checking example host configuration...')
+ utils.Logger.info('Checking example host configuration...\n')
failures = False
for hostname in EXAMPLE_CONFIG:
if not any(1 for e in config_data if e['alias'] == hostname):
- fail('Could not find host "{0}"'.format(hostname))
+ utils.Logger.fail('Could not find host "{0}"\n'.format(hostname))
failures = True
else:
- success('Found host "{0}"'.format(hostname))
+ utils.Logger.ok('Found host "{0}"\n'.format(hostname))
return not failures
Return whether the example services exist in the given "services" table
"""
- info('Checking example service configuration...')
+ utils.Logger.info('Checking example service configuration...\n')
failures = False
for hostname, servicename in ((h, s) for h, ss in EXAMPLE_CONFIG.iteritems()
for s in ss):
if not any(1 for c in config_data
if c['alias'] == hostname and
c['display_name'] == servicename):
- fail('Could not find service "{0}" on host "{1}"'
- ''.format(servicename, hostname))
+ utils.Logger.fail('Could not find service "{0}" on host "{1}"\n'
+ ''.format(servicename, hostname))
failures = True
else:
- success('Found service "{0}" on host "{1}"'
- ''.format(servicename, hostname))
+ utils.Logger.ok('Found service "{0}" on host "{1}"\n'
+ ''.format(servicename, hostname))
return not failures
Return whether the example hosts are checked as scheduled
"""
- info('Checking last host status updates...')
+ utils.Logger.info('Checking last host status updates...\n')
failures = False
for host_info in check_info:
if host_info['alias'] == 'localhost':
last_check = datetime.fromtimestamp(float(host_info['last_check']))
if datetime.now() - last_check > timedelta(minutes=CHECK_INTERVAL,
seconds=10):
- fail('The last status update of host "{0}" was more than {1} '
- 'minutes ago'.format(host_info['alias'], CHECK_INTERVAL))
+ utils.Logger.fail('The last status update of host "{0}" was'
+ ' more than {1} minutes ago\n'
+ ''.format(host_info['alias'], CHECK_INTERVAL))
failures = True
else:
- success('Host "{0}" is being updated'.format(host_info['alias']))
+ utils.Logger.ok('Host "{0}" is being updated\n'
+ ''.format(host_info['alias']))
elif host_info['alias'] == 'nsca-ng':
if float(host_info['last_check']) > 0:
- fail('The host "{0}" was checked even though it has'
- ' no check service'.format(host_info['alias']))
+ utils.Logger.fail('The host "{0}" was checked even'
+ ' though it has no check service'
+ ''.format(host_info['alias']))
failures = True
else:
- success('Host "{0}" is not being checked because there '
- 'is no check service'.format(host_info['alias']))
+ utils.Logger.ok('Host "{0}" is not being checked because '
+ 'there is no check service\n'
+ ''.format(host_info['alias']))
else:
- info('Skipping host "{0}"'.format(host_info['alias']))
+ utils.Logger.info('Skipping host "{0}"\n'
+ ''.format(host_info['alias']))
return not failures
Return whether the example services are checked as scheduled
"""
- info('Checking last service status updates...')
+ utils.Logger.info('Checking last service status updates...\n')
failures = False
for svc_info in check_info:
if svc_info['display_name'] in EXAMPLE_CONFIG.get(svc_info['alias'], []):
last_check = datetime.fromtimestamp(float(svc_info['last_check']))
if datetime.now() - last_check > timedelta(minutes=CHECK_INTERVAL,
seconds=10):
- fail('The last status update of service "{0}" on'
- ' host "{1}" was more than {2} minutes ago'
- ''.format(svc_info['display_name'], svc_info['alias'],
- CHECK_INTERVAL))
+ utils.Logger.fail('The last status update of service "{0}" on '
+ 'host "{1}" was more than {2} minutes ago\n'
+ ''.format(svc_info['display_name'],
+ svc_info['alias'],
+ CHECK_INTERVAL))
failures = True
else:
- success('Service "{0}" on host "{1}" is being updated'
- ''.format(svc_info['display_name'], svc_info['alias']))
+ utils.Logger.ok('Service "{0}" on host "{1}" is being updated\n'
+ ''.format(svc_info['display_name'],
+ svc_info['alias']))
else:
- info('Skipping service "{0}" on host "{1}"'
- ''.format(svc_info['display_name'], svc_info['alias']))
+ utils.Logger.info('Skipping service "{0}" on host "{1}"\n'
+ ''.format(svc_info['display_name'],
+ svc_info['alias']))
return not failures
and refers to its very last hard status change
"""
- info('Checking status log for host "localhost"...')
+ utils.Logger.info('Checking status log for host "localhost"...\n')
if logentry_info and logentry_info[0]['alias'] == 'localhost':
entry_time = datetime.fromtimestamp(float(logentry_info[0]['entry_time']))
state_time = datetime.fromtimestamp(float(logentry_info[0]['state_time']))
if entry_time - state_time > timedelta(seconds=10):
- return fail('The last hard state of host "localhost"'
- ' seems not to have been logged')
+ utils.Logger.fail('The last hard state of host "localhost"'
+ ' seems not to have been logged\n')
+ return False
else:
- return fail('No logs found in the IDO for host "localhost"')
+ utils.Logger.fail('No logs found in the IDO for host "localhost"\n')
+ return False
- return success('The last hard state of host "localhost" was properly logged')
+ utils.Logger.ok('The last hard state of host "localhost"'
+ ' was properly logged\n')
+ return True
from __future__ import unicode_literals
import os
+import sys
import time
import json
import socket
def run_mysql_query(query, path):
p = subprocess.Popen([path] + MYSQL_PARAMS + [query.encode('utf-8')],
stdout=subprocess.PIPE)
- return _parse_mysql_result([l.decode('utf-8') for l in p.stdout.readlines()])
+ Logger.debug('Sent MYSQL query: {0!r}\n'.format(query))
+ resultset = [l.decode('utf-8') for l in p.stdout.readlines()]
+ Logger.debug('Received MYSQL resultset: {0!r}\n'
+ ''.format(''.join(resultset)), True)
+ return _parse_mysql_result(resultset)
def _parse_mysql_result(resultset):
def run_pgsql_query(query, path):
p = subprocess.Popen([path] + PGSQL_PARAMS + [query.encode('utf-8')],
stdout=subprocess.PIPE, env=PGSQL_ENVIRONMENT)
- return _parse_pgsql_result([l.decode('utf-8') for l in p.stdout.readlines()])
+ Logger.debug('Sent PostgreSQL query: {0!r}\n'.format(query))
+ resultset = [l.decode('utf-8') for l in p.stdout.readlines()]
+ Logger.debug('Received PostgreSQL resultset: {0!r}\n'
+ ''.format(''.join(resultset)), True)
+ return _parse_pgsql_result(resultset)
def _parse_pgsql_result(resultset):
def connect(self):
self.sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
+ Logger.debug('Opened UNIX stream socket\n', True)
self.sock.connect(self.path)
+ Logger.debug('Connected to Livestatus socket: {0}\n'.format(self.path),
+ True)
self._connected = True
def reconnect(self, timeout=30):
+ Logger.debug('Reconnecting to Livestatus socket\n', True)
start = time.time()
while not self._connected and time.time() - start < timeout:
try:
self.connect()
- except socket.error:
+ except socket.error, error:
+ Logger.debug('Could not connect: {0}\n'.format(error), True)
# Icinga2 does some "magic" with the socket during startup
# which causes random errors being raised (EACCES, ENOENT, ..)
# so we just ignore them until the timeout is reached
def close(self):
if self._connected:
self.sock.shutdown(socket.SHUT_RDWR)
+ Logger.debug('Shutted down Livestatus connection\n', True)
self.sock.close()
+ Logger.debug('Closed Livestatus socket\n', True)
self._connected = False
def query(self, command):
full_query = '\n'.join([query] + self.options)
self.sock.sendall((full_query + '\n\n').encode('utf-8'))
+ Logger.debug('Sent Livestatus query: {0!r}\n'.format(full_query))
def recv(self):
if not self._connected:
except ValueError:
pass
+ Logger.debug('Received Livestatus response: {0!r} (Header was: {1!r})'
+ '\n'.format(response, response_header), True)
return response_code, response
+
+class Logger(object):
+ INFO = 1
+ OK = 2
+ FAIL = 3
+ ERROR = 4
+ DEBUG_STD = 5
+ DEBUG_EXT = 6
+
+ VERBOSITY = None
+
+ @classmethod
+ def permitted(cls, severity):
+ if cls.VERBOSITY is None:
+ cls.VERBOSITY = next((int(sys.argv.pop(i).partition('=')[2])
+ for i, a in enumerate(sys.argv)
+ if a.startswith('--verbosity=')), 1)
+
+ return (severity == cls.INFO and cls.VERBOSITY >= 1) or \
+ (severity == cls.OK and cls.VERBOSITY >= 1) or \
+ (severity == cls.FAIL and cls.VERBOSITY >= 1) or \
+ (severity == cls.ERROR and cls.VERBOSITY >= 1) or \
+ (severity == cls.DEBUG_STD and cls.VERBOSITY >= 2) or \
+ (severity == cls.DEBUG_EXT and cls.VERBOSITY >= 3)
+
+ @staticmethod
+ def write(text, stderr=False):
+ if stderr:
+ sys.stderr.write(text)
+ sys.stderr.flush()
+ else:
+ sys.stdout.write(text)
+ sys.stdout.flush()
+
+ @classmethod
+ def log(cls, severity, text):
+ if severity == cls.INFO and cls.permitted(cls.INFO):
+ cls.write('\x00[INFO] {0}'.format(text))
+ elif severity == cls.ERROR and cls.permitted(cls.ERROR):
+ cls.write('\x00[ERROR] {0}'.format(text))
+ elif severity == cls.FAIL and cls.permitted(cls.FAIL):
+ cls.write('\x00[FAIL] {0}'.format(text))
+ elif severity == cls.OK and cls.permitted(cls.OK):
+ cls.write('\x00[OK] {0}'.format(text))
+ elif severity == cls.DEBUG_STD and cls.permitted(cls.DEBUG_STD):
+ cls.write('\x00\x00[DEBUG] {0}'.format(text))
+ elif severity == cls.DEBUG_EXT and cls.permitted(cls.DEBUG_EXT):
+ cls.write('\x00\x00\x00\x00[DEBUG] {0}'.format(text))
+ else:
+ return False
+ return True
+
+ @classmethod
+ def info(cls, text):
+ return cls.log(cls.INFO, text)
+
+ @classmethod
+ def error(cls, text):
+ return cls.log(cls.ERROR, text)
+
+ @classmethod
+ def fail(cls, text):
+ return cls.log(cls.FAIL, text)
+
+ @classmethod
+ def ok(cls, text):
+ return cls.log(cls.OK, text)
+
+ @classmethod
+ def debug(cls, text, extended=False):
+ return cls.log(cls.DEBUG_EXT if extended else cls.DEBUG_STD, text)
+
class Logger(object):
INFO = 1
- ERROR = 2
+ OK = 2
FAIL = 3
- OK = 4
+ ERROR = 4
+ DEBUG_STD = 5
+ DEBUG_EXT = 6
+
+ VERBOSITY = 0
+ OUTPUT_LENGTH = 1024
@staticmethod
def write(text, stderr=False):
if stderr:
- sys.stderr.write(text)
+ sys.stderr.write(text.encode('utf-8'))
sys.stderr.flush()
else:
- sys.stdout.write(text)
+ sys.stdout.write(text.encode('utf-8'))
sys.stdout.flush()
+ @classmethod
+ def set_verbosity(cls, verbosity):
+ cls.VERBOSITY = verbosity
+
@classmethod
def log(cls, severity, text):
- if severity == cls.INFO:
+ if severity == cls.INFO and cls.VERBOSITY >= 1:
cls.write('\033[1;94m[INFO]\033[1;0m {0}'.format(text))
- elif severity == cls.ERROR:
+ elif severity == cls.ERROR and cls.VERBOSITY >= 1:
cls.write('\033[1;33m[ERROR]\033[1;0m {0}'.format(text), True)
- elif severity == cls.FAIL:
+ elif severity == cls.FAIL and cls.VERBOSITY >= 1:
cls.write('\033[1;31m[FAIL] {0}\033[1;0m'.format(text))
- elif severity == cls.OK:
+ elif severity == cls.OK and cls.VERBOSITY >= 1:
cls.write('\033[1;32m[OK]\033[1;0m {0}'.format(text))
+ elif severity == cls.DEBUG_STD and cls.VERBOSITY >= 2:
+ cls.write('\033[1;90m[DEBUG]\033[1;0m {0}'.format(text))
+ elif severity == cls.DEBUG_EXT and cls.VERBOSITY >= 3:
+ if cls.VERBOSITY < 4 and len(text) > cls.OUTPUT_LENGTH:
+ suffix = '... (Truncated to {0} bytes)\n' \
+ ''.format(cls.OUTPUT_LENGTH)
+ text = text[:cls.OUTPUT_LENGTH] + suffix
+ cls.write('\033[1;90m[DEBUG]\033[1;0m {0}'.format(text))
+ else:
+ return False
+ return True
@classmethod
def info(cls, text):
- cls.log(cls.INFO, text)
+ return cls.log(cls.INFO, text)
@classmethod
def error(cls, text):
- cls.log(cls.ERROR, text)
+ return cls.log(cls.ERROR, text)
@classmethod
def fail(cls, text):
- cls.log(cls.FAIL, text)
+ return cls.log(cls.FAIL, text)
@classmethod
def ok(cls, text):
- cls.log(cls.OK, text)
+ return cls.log(cls.OK, text)
+
+ @classmethod
+ def debug(cls, text, extended=False):
+ return cls.log(cls.DEBUG_EXT if extended else cls.DEBUG_STD, text)
class TestSuite(object):
def run(self):
for path in self._tests:
test_name = os.path.basename(path)
- Logger.info('Copying test "{0}" to remote machine\n'.format(test_name))
+ Logger.debug('Copying test "{0}" to remote machine\n'.format(test_name))
self._copy_test(path)
self._apply_setup_routines(test_name, 'setup')
- Logger.info('Running test "{0}"...\n'.format(test_name))
+ note_printed = Logger.info('Running test "{0}"...\n'.format(test_name))
result = self._run_test(path)
Logger.info('Test "{0}" has finished (Total tests: {1}, Failures: {2})\n'
''.format(test_name, result['total'], result['failures']))
self._apply_setup_routines(test_name, 'teardown')
- Logger.info('Removing test "{0}" from remote machine\n'.format(test_name))
+ Logger.debug('Removing test "{0}" from remote machine\n'.format(test_name))
self._remove_test(test_name)
self._results[test_name] = result
- Logger.write('\n')
+ if note_printed:
+ Logger.write('\n')
def _apply_setup_routines(self, test_name, context):
instructions = next((t[1].get(context)
for t in self._config.get('setups', {}).iteritems()
if re.match(t[0], test_name)), None)
if instructions is not None:
- Logger.info('Applying {0} routines for test "{1}" .. '
- ''.format(context, test_name))
+ note_printed = Logger.info('Applying {0} routines for test "{1}" .. '
+ ''.format(context, test_name))
for instruction in instructions.get('copy', []):
source, _, destination = instruction.partition('>>')
self._copy_file(source.strip(), destination.strip())
self._remove_file(filepath)
for command in instructions.get('exec', []):
self._exec_command(command)
- Logger.write('Done\n')
+ if note_printed:
+ Logger.write('Done\n')
def _remove_file(self, path):
command = self._config['commands']['clean'].format(path)
command = self._config['commands']['exec'].format(command)
rc = subprocess.call(command, stdout=DEVNULL, shell=True)
if rc != 0:
- Logger.error('Command "{0}" exited with exit code "{1}"' \
+ Logger.error('Command "{0}" exited with exit code "{1}"\n' \
''.format(command, rc))
def _copy_file(self, source, destination):
command = self._config['commands']['copy'].format(source, destination)
rc = subprocess.call(command, stdout=DEVNULL, shell=True)
if rc != 0:
- Logger.error('Cannot copy file "{0}" to "{1}" ({2})' \
+ Logger.error('Cannot copy file "{0}" to "{1}" ({2})\n' \
''.format(source, destination, rc))
def _copy_test(self, path):
command = self._config['commands']['exec']
target = os.path.join(self._config['settings']['test_root'],
os.path.basename(path))
- p = subprocess.Popen(command.format(target), stdout=subprocess.PIPE,
- stderr=subprocess.PIPE, shell=True)
+ options = ['--verbosity={0}'.format(Logger.VERBOSITY)]
+ p = subprocess.Popen(command.format(' '.join([target] + options)),
+ stdout=subprocess.PIPE, stderr=subprocess.PIPE,
+ shell=True)
output, test_count, failed_tests = self._watch_output(p.stdout)
return {
'total': test_count,
if not line:
break
+ verbosity_level = line.count('\x00')
+ line = line[verbosity_level:]
if line.startswith('[ERROR] '):
Logger.error(line[8:])
+ elif line.startswith('[DEBUG] '):
+ Logger.debug(line[8:], verbosity_level == 4)
elif line.startswith('[FAIL] '):
Logger.fail(line[7:])
failures += 1
def parse_commandline():
- parser = OptionParser(version='0.2')
+ parser = OptionParser(version='0.5')
parser.add_option('-C', '--config', default="run_tests.conf",
help='The path to the config file to use [%default]')
parser.add_option('-R', '--results',
help='The file where to store the test results')
+ parser.add_option('-v', '--verbose', action='count', default=1,
+ help='Be more verbose (Maximum output: -vvv)')
+ parser.add_option('-q', '--quiet', action='count', default=0,
+ help='Be less verbose')
return parser.parse_args()
for path in (p for a in arguments for p in glob.glob(a)):
suite.add_test(path)
+ Logger.set_verbosity(options.verbose - options.quiet)
suite.run()
if options.results is not None:
#!/bin/sh
vagrant ssh-config > ssh_config
-./run_tests.py *.test
+./run_tests.py $@ *.test
rm -f ssh_config
projects / icinga2 / commitdiff