Real time logging implemented

This commit is contained in:
VakarisZ 2019-10-01 16:11:53 +03:00
parent 73d434119d
commit f962894038
9 changed files with 52 additions and 37 deletions

View File

@ -9,6 +9,7 @@ from envs.monkey_zoo.blackbox.island_client.monkey_island_requests import Monkey
SLEEP_BETWEEN_REQUESTS_SECONDS = 0.5 SLEEP_BETWEEN_REQUESTS_SECONDS = 0.5
MONKEY_TEST_ENDPOINT = 'api/test/monkey' MONKEY_TEST_ENDPOINT = 'api/test/monkey'
LOG_TEST_ENDPOINT = 'api/test/log' LOG_TEST_ENDPOINT = 'api/test/log'
LOGGER = logging.getLogger(__name__)
def avoid_race_condition(func): def avoid_race_condition(func):
@ -31,9 +32,9 @@ class MonkeyIslandClient(object):
def run_monkey_local(self): def run_monkey_local(self):
response = self.requests.post_json("api/local-monkey", dict_data={"action": "run"}) response = self.requests.post_json("api/local-monkey", dict_data={"action": "run"})
if MonkeyIslandClient.monkey_ran_successfully(response): if MonkeyIslandClient.monkey_ran_successfully(response):
logging.info("Running the monkey.") LOGGER.info("Running the monkey.")
else: else:
logging.error("Failed to run the monkey.") LOGGER.error("Failed to run the monkey.")
assert False assert False
@staticmethod @staticmethod
@ -43,17 +44,17 @@ class MonkeyIslandClient(object):
@avoid_race_condition @avoid_race_condition
def kill_all_monkeys(self): def kill_all_monkeys(self):
if self.requests.get("api", {"action": "killall"}).ok: if self.requests.get("api", {"action": "killall"}).ok:
logging.info("Killing all monkeys after the test.") LOGGER.info("Killing all monkeys after the test.")
else: else:
logging.error("Failed to kill all monkeys.") LOGGER.error("Failed to kill all monkeys.")
assert False assert False
@avoid_race_condition @avoid_race_condition
def reset_env(self): def reset_env(self):
if self.requests.get("api", {"action": "reset"}).ok: if self.requests.get("api", {"action": "reset"}).ok:
logging.info("Resetting environment after the test.") LOGGER.info("Resetting environment after the test.")
else: else:
logging.error("Failed to reset the environment.") LOGGER.error("Failed to reset the environment.")
assert False assert False
def find_monkeys_in_db(self, query): def find_monkeys_in_db(self, query):

View File

@ -5,6 +5,7 @@ import logging
NO_AUTH_CREDS = '55e97c9dcfd22b8079189ddaeea9bce8125887e3237b800c6176c9afa80d2062' \ NO_AUTH_CREDS = '55e97c9dcfd22b8079189ddaeea9bce8125887e3237b800c6176c9afa80d2062' \
'8d2c8d0b1538d2208c1444ac66535b764a3d902b35e751df3faec1e477ed3557' '8d2c8d0b1538d2208c1444ac66535b764a3d902b35e751df3faec1e477ed3557'
LOGGER = logging.getLogger(__name__)
class MonkeyIslandRequests(object): class MonkeyIslandRequests(object):
@ -16,7 +17,7 @@ class MonkeyIslandRequests(object):
try: try:
return self.get_jwt_from_server() return self.get_jwt_from_server()
except requests.ConnectionError: except requests.ConnectionError:
logging.error("Unable to connect to island, aborting!") LOGGER.error("Unable to connect to island, aborting!")
assert False assert False
def get_jwt_from_server(self): def get_jwt_from_server(self):

View File

@ -3,6 +3,8 @@ import os
import logging import logging
from bson import ObjectId from bson import ObjectId
LOGGER = logging.getLogger(__name__)
class MonkeyLog(object): class MonkeyLog(object):
def __init__(self, monkey, log_dir_path): def __init__(self, monkey, log_dir_path):
@ -12,7 +14,7 @@ class MonkeyLog(object):
def download_log(self, island_client): def download_log(self, island_client):
log = island_client.find_log_in_db({'monkey_id': ObjectId(self.monkey['id'])}) log = island_client.find_log_in_db({'monkey_id': ObjectId(self.monkey['id'])})
if not log: if not log:
logging.error("Log for monkey {} not found".format(self.monkey['ip_addresses'][0])) LOGGER.error("Log for monkey {} not found".format(self.monkey['ip_addresses'][0]))
return False return False
else: else:
self.write_log_to_file(log) self.write_log_to_file(log)

View File

@ -2,6 +2,8 @@ import logging
from envs.monkey_zoo.blackbox.log_handlers.monkey_log import MonkeyLog from envs.monkey_zoo.blackbox.log_handlers.monkey_log import MonkeyLog
LOGGER = logging.getLogger(__name__)
class MonkeyLogsDownloader(object): class MonkeyLogsDownloader(object):
@ -11,7 +13,7 @@ class MonkeyLogsDownloader(object):
self.monkey_log_paths = [] self.monkey_log_paths = []
def download_monkey_logs(self): def download_monkey_logs(self):
logging.info("Downloading each monkey log.") LOGGER.info("Downloading each monkey log.")
all_monkeys = self.island_client.get_all_monkeys_from_db() all_monkeys = self.island_client.get_all_monkeys_from_db()
for monkey in all_monkeys: for monkey in all_monkeys:
downloaded_log_path = self._download_monkey_log(monkey) downloaded_log_path = self._download_monkey_log(monkey)

View File

@ -7,6 +7,7 @@ from envs.monkey_zoo.blackbox.log_handlers.monkey_log_parser import MonkeyLogPar
from envs.monkey_zoo.blackbox.log_handlers.monkey_logs_downloader import MonkeyLogsDownloader from envs.monkey_zoo.blackbox.log_handlers.monkey_logs_downloader import MonkeyLogsDownloader
LOG_DIR_NAME = 'logs' LOG_DIR_NAME = 'logs'
LOGGER = logging.getLogger(__name__)
class TestLogsHandler(object): class TestLogsHandler(object):
@ -18,7 +19,7 @@ class TestLogsHandler(object):
def parse_test_logs(self): def parse_test_logs(self):
log_paths = self.download_logs() log_paths = self.download_logs()
if not log_paths: if not log_paths:
logging.error("No logs were downloaded. Maybe no monkeys were ran " LOGGER.error("No logs were downloaded. Maybe no monkeys were ran "
"or early exception prevented log download?") "or early exception prevented log download?")
return return
TestLogsHandler.parse_logs(log_paths) TestLogsHandler.parse_logs(log_paths)
@ -33,7 +34,7 @@ class TestLogsHandler(object):
try: try:
os.mkdir(self.log_dir_path) os.mkdir(self.log_dir_path)
except Exception as e: except Exception as e:
logging.error("Can't create a dir for test logs: {}".format(e)) LOGGER.error("Can't create a dir for test logs: {}".format(e))
@staticmethod @staticmethod
def delete_log_folder_contents(log_dir_path): def delete_log_folder_contents(log_dir_path):
@ -43,7 +44,7 @@ class TestLogsHandler(object):
@staticmethod @staticmethod
def parse_logs(log_paths): def parse_logs(log_paths):
for log_path in log_paths: for log_path in log_paths:
logging.info("Info from log at {}".format(log_path)) print("Info from log at {}".format(log_path))
log_parser = MonkeyLogParser(log_path) log_parser = MonkeyLogParser(log_path)
log_parser.print_errors() log_parser.print_errors()
log_parser.print_warnings() log_parser.print_warnings()

View File

@ -0,0 +1,5 @@
[pytest]
log_cli = 1
log_cli_level = INFO
log_cli_format = %(asctime)s [%(levelname)s] %(message)s
log_cli_date_format=%H:%M:%S

View File

@ -17,6 +17,7 @@ GCP_TEST_MACHINE_LIST = ['sshkeys-11', 'sshkeys-12', 'elastic-4', 'elastic-5', '
'mimikatz-14', 'mimikatz-15', 'final-test-struts2-23', 'final-test-struts2-24', 'mimikatz-14', 'mimikatz-15', 'final-test-struts2-23', 'final-test-struts2-24',
'tunneling-9', 'tunneling-10', 'tunneling-11', 'weblogic-18', 'weblogic-19', 'shellshock-8'] 'tunneling-9', 'tunneling-10', 'tunneling-11', 'weblogic-18', 'weblogic-19', 'shellshock-8']
LOG_DIR_PATH = "./logs" LOG_DIR_PATH = "./logs"
LOGGER = logging.getLogger(__name__)
@pytest.fixture(autouse=True, scope='session') @pytest.fixture(autouse=True, scope='session')
@ -33,7 +34,7 @@ def GCPHandler(request):
@pytest.fixture(autouse=True, scope='session') @pytest.fixture(autouse=True, scope='session')
def delete_logs(): def delete_logs():
logging.info("Deleting monkey logs before new tests.") LOGGER.info("Deleting monkey logs before new tests.")
TestLogsHandler.delete_log_folder_contents(TestMonkeyBlackbox.get_log_dir_path()) TestLogsHandler.delete_log_folder_contents(TestMonkeyBlackbox.get_log_dir_path())

View File

@ -3,12 +3,12 @@ from time import sleep
import logging import logging
from envs.monkey_zoo.blackbox.utils.test_timer import TestTimer from envs.monkey_zoo.blackbox.utils.test_timer import TestTimer
from envs.monkey_zoo.blackbox.log_handlers.test_logs_handler import TestLogsHandler
MAX_TIME_FOR_MONKEYS_TO_DIE = 5*60 MAX_TIME_FOR_MONKEYS_TO_DIE = 5 * 60
WAIT_TIME_BETWEEN_REQUESTS = 10 WAIT_TIME_BETWEEN_REQUESTS = 10
TIME_FOR_MONKEY_PROCESS_TO_FINISH = 40 TIME_FOR_MONKEY_PROCESS_TO_FINISH = 40
DELAY_BETWEEN_ANALYSIS = 3 DELAY_BETWEEN_ANALYSIS = 3
LOGGER = logging.getLogger(__name__)
class BasicTest(object): class BasicTest(object):
@ -35,10 +35,10 @@ class BasicTest(object):
self.island_client.reset_env() self.island_client.reset_env()
def print_test_starting_info(self): def print_test_starting_info(self):
logging.info("Started {} test".format(self.name)) LOGGER.info("Started {} test".format(self.name))
logging.info("Machines participating in test:") LOGGER.info("Machines participating in test:")
logging.info(" ".join(self.config_parser.get_ips_of_targets())) LOGGER.info(" ".join(self.config_parser.get_ips_of_targets()))
logging.info("") print("")
def test_until_timeout(self): def test_until_timeout(self):
timer = TestTimer(self.timeout) timer = TestTimer(self.timeout)
@ -51,12 +51,12 @@ class BasicTest(object):
assert False assert False
def log_success(self, timer): def log_success(self, timer):
logging.info(self.get_analyzer_logs()) LOGGER.info(self.get_analyzer_logs())
logging.info("{} test passed, time taken: {:.1f} seconds.".format(self.name, timer.get_time_taken())) LOGGER.info("{} test passed, time taken: {:.1f} seconds.".format(self.name, timer.get_time_taken()))
def log_failure(self, timer): def log_failure(self, timer):
logging.info(self.get_analyzer_logs()) LOGGER.info(self.get_analyzer_logs())
logging.error("{} test failed because of timeout. Time taken: {:.1f} seconds.".format(self.name, LOGGER.error("{} test failed because of timeout. Time taken: {:.1f} seconds.".format(self.name,
timer.get_time_taken())) timer.get_time_taken()))
def all_analyzers_pass(self): def all_analyzers_pass(self):
@ -68,7 +68,7 @@ class BasicTest(object):
def get_analyzer_logs(self): def get_analyzer_logs(self):
log = "" log = ""
for analyzer in self.analyzers: for analyzer in self.analyzers:
log += "\n"+analyzer.log.get_contents() log += "\n" + analyzer.log.get_contents()
return log return log
def wait_until_monkeys_die(self): def wait_until_monkeys_die(self):
@ -77,11 +77,11 @@ class BasicTest(object):
sleep(WAIT_TIME_BETWEEN_REQUESTS) sleep(WAIT_TIME_BETWEEN_REQUESTS)
time_passed += WAIT_TIME_BETWEEN_REQUESTS time_passed += WAIT_TIME_BETWEEN_REQUESTS
if time_passed > MAX_TIME_FOR_MONKEYS_TO_DIE: if time_passed > MAX_TIME_FOR_MONKEYS_TO_DIE:
logging.error("Some monkeys didn't die after the test, failing") LOGGER.error("Some monkeys didn't die after the test, failing")
assert False assert False
def parse_logs(self): def parse_logs(self):
logging.info("\nParsing test logs:") LOGGER.info("\nParsing test logs:")
self.log_handler.parse_test_logs() self.log_handler.parse_test_logs()
@staticmethod @staticmethod

View File

@ -2,6 +2,8 @@ import subprocess
import logging import logging
LOGGER = logging.getLogger(__name__)
class GCPHandler(object): class GCPHandler(object):
@ -15,28 +17,28 @@ class GCPHandler(object):
try: try:
# pass the key file to gcp # pass the key file to gcp
subprocess.call(GCPHandler.get_auth_command(key_path), shell=True) subprocess.call(GCPHandler.get_auth_command(key_path), shell=True)
logging.info("GCP Handler passed key") LOGGER.info("GCP Handler passed key")
# set project # set project
subprocess.call(GCPHandler.get_set_project_command(project_id), shell=True) subprocess.call(GCPHandler.get_set_project_command(project_id), shell=True)
logging.info("GCP Handler set project") LOGGER.info("GCP Handler set project")
logging.info("GCP Handler initialized successfully") LOGGER.info("GCP Handler initialized successfully")
except Exception as e: except Exception as e:
logging.error("GCP Handler failed to initialize: %s." % e) LOGGER.error("GCP Handler failed to initialize: %s." % e)
def start_machines(self, machine_list): def start_machines(self, machine_list):
logging.info("Setting up all GCP machines...") LOGGER.info("Setting up all GCP machines...")
try: try:
subprocess.call((GCPHandler.MACHINE_STARTING_COMMAND % (machine_list, self.zone)), shell=True) subprocess.call((GCPHandler.MACHINE_STARTING_COMMAND % (machine_list, self.zone)), shell=True)
logging.info("GCP machines successfully started.") LOGGER.info("GCP machines successfully started.")
except Exception as e: except Exception as e:
logging.error("GCP Handler failed to start GCP machines: %s" % e) LOGGER.error("GCP Handler failed to start GCP machines: %s" % e)
def stop_machines(self, machine_list): def stop_machines(self, machine_list):
try: try:
subprocess.call((GCPHandler.MACHINE_STOPPING_COMMAND % (machine_list, self.zone)), shell=True) subprocess.call((GCPHandler.MACHINE_STOPPING_COMMAND % (machine_list, self.zone)), shell=True)
logging.info("GCP machines stopped successfully.") LOGGER.info("GCP machines stopped successfully.")
except Exception as e: except Exception as e:
logging.error("GCP Handler failed to stop network machines: %s" % e) LOGGER.error("GCP Handler failed to stop network machines: %s" % e)
@staticmethod @staticmethod
def get_auth_command(key_path): def get_auth_command(key_path):