def test_es_log_extra_argument_insertion(self): self.log.info("About to test elasticsearch insertion") handler = CMRESHandler(hosts=[{ 'host': self.getESHost(), 'port': self.getESPort() }], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, es_index_name="pythontest", es_additional_fields={ 'App': 'Test', 'Environment': 'Dev' }, raise_on_indexing_exceptions=True) es_test_server_is_up = handler.test_es_source() self.log.info( "ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEqual(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.addHandler(handler) log.warning("Extra arguments Message", extra={ "Arg1": 300, "Arg2": 400 }) self.assertEqual(1, len(handler._buffer)) self.assertEqual(handler._buffer[0]['Arg1'], 300) self.assertEqual(handler._buffer[0]['Arg2'], 400) self.assertEqual(handler._buffer[0]['App'], 'Test') self.assertEqual(handler._buffer[0]['Environment'], 'Dev') handler.flush() self.assertEqual(0, len(handler._buffer))
def test_ping(self): handler = CMRESHandler(hosts=[{'host': 'localhost', 'port': 9200}], auth_type=CMRESHandler.AuthType.NO_AUTH, es_index_name="pythontest", use_ssl=False) es_test_server_is_up = handler.test_es_source() self.assertEquals(True, es_test_server_is_up)
def test_buffered_log_insertion_flushed_when_buffer_full(self): handler = CMRESHandler(hosts=[{ 'host': self.getESHost(), 'port': self.getESPort() }], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, buffer_size=2, flush_frequency_in_sec=1000, es_index_name="pythontest", es_additional_fields={ 'App': 'Test', 'Environment': 'Dev' }, raise_on_indexing_exceptions=True) es_test_server_is_up = handler.test_es_source() self.log.info( "ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEqual(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.setLevel(logging.DEBUG) log.addHandler(handler) log.warning("First Message") log.info("Seccond Message") self.assertEqual(0, len(handler._buffer)) handler.close()
def test_ping(self): handler = CMRESHandler(hosts=[{'host': self.getESHost(), 'port': self.getESPort()}], auth_type=CMRESHandler.AuthType.NO_AUTH, es_index_name="pythontest", use_ssl=False, raise_on_indexing_exceptions=True) es_test_server_is_up = handler.test_es_source() self.assertEqual(True, es_test_server_is_up)
def test_ping(self): handler = CMRESHandler(hosts=[{'host': self.getESHost(), 'port': self.getESPort()}], auth_type=CMRESHandler.AuthType.NO_AUTH, es_index_name="pythontest", use_ssl=False, raise_on_indexing_exceptions=True) es_test_server_is_up = handler.test_es_source() self.assertEqual(True, es_test_server_is_up)
def test_buffered_log_insertion_flushed_when_buffer_full(self): handler = CMRESHandler(hosts=[{'host': 'localhost', 'port': 9200}], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, buffer_size=2, flush_frequency_in_sec=1000, es_index_name="pythontest", es_additional_fields={'App': 'Test', 'Environment': 'Dev'}) es_test_server_is_up = handler.test_es_source() self.log.info("ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEquals(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.setLevel(logging.DEBUG) log.addHandler(handler) log.warning("First Message") log.info("Seccond Message") self.assertEquals(0, len(handler._buffer)) handler.close()
def test_new_index_has_messages(self): index_name = "pythontest-index-messages" handler = CMRESHandler(hosts=[{ 'host': self.getESHost(), 'port': self.getESPort() }], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, es_index_name=index_name, es_additional_fields={ 'App': 'Test', 'Environment': 'Dev' }, raise_on_indexing_exceptions=True) message = "Specific message %s" es_test_server_is_up = handler.test_es_source() index = handler._index_name_func.__func__(index_name) client = handler._client client.indices.delete(index, ignore=404) self.log.info( "ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEqual(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.setLevel(logging.DEBUG) log.addHandler(handler) log.info(message, 1) log.info(message, 'str') handler.flush() self.assertEqual(0, len(handler._buffer)) # Wait a little while elasticsearch creating mapping and indexing messages time.sleep(1) self.assertEqual( 2, client.search(index, body={"query": { "match": { 'message': message } }})['hits']['total']) handler.close()
def test_buffered_log_insertion_after_interval_expired(self): handler = CMRESHandler(hosts=[{'host': 'localhost', 'port': 9200}], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, flush_frequency_in_sec=0.1, es_index_name="pythontest", es_additional_fields={'App': 'Test', 'Environment': 'Dev'}) es_test_server_is_up = handler.test_es_source() self.log.info("ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEquals(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.addHandler(handler) log.warning("Extra arguments Message", extra={"Arg1": 300, "Arg2": 400}) self.assertEquals(1, len(handler._buffer)) self.assertEquals(handler._buffer[0]['Arg1'], 300) self.assertEquals(handler._buffer[0]['Arg2'], 400) self.assertEquals(handler._buffer[0]['App'], 'Test') self.assertEquals(handler._buffer[0]['Environment'], 'Dev') time.sleep(1) self.assertEquals(0, len(handler._buffer))
def test_es_log_extra_argument_insertion(self): self.log.info("About to test elasticsearch insertion") handler = CMRESHandler(hosts=[{'host': 'localhost', 'port': 9200}], auth_type=CMRESHandler.AuthType.NO_AUTH, use_ssl=False, es_index_name="pythontest", es_additional_fields={'App': 'Test', 'Environment': 'Dev'}) es_test_server_is_up = handler.test_es_source() self.log.info("ES services status is: {0!s}".format(es_test_server_is_up)) self.assertEquals(True, es_test_server_is_up) log = logging.getLogger("PythonTest") log.addHandler(handler) log.warning("Extra arguments Message", extra={"Arg1": 300, "Arg2": 400}) self.assertEquals(1, len(handler._buffer)) self.assertEquals(handler._buffer[0]['Arg1'], 300) self.assertEquals(handler._buffer[0]['Arg2'], 400) self.assertEquals(handler._buffer[0]['App'], 'Test') self.assertEquals(handler._buffer[0]['Environment'], 'Dev') handler.flush() self.assertEquals(0, len(handler._buffer))
class CallbackModule(CallbackBase): # Callback CALLBACK_VERSION = 2.0 CALLBACK_NEEDS_WHITELIST = True CALLBACK_TYPE = 'aggregate' CALLBACK_NAME = 'elastic' NAME = CALLBACK_NAME _load_name = NAME def __init__(self): super(CallbackModule, self).__init__() # Initialize data loader self.loader = DataLoader() # Get the configuration self._config_data = self._read_config_data( self._get_config_file_name()) # Initialize logger self._initialize_logger() ########################################################################### # Ansible ########################################################################### # Ansible ACTIONS ANSIBLE_ACTION_START = 'START' ANSIBLE_ACTION_RUNNING = 'RUNNING' ANSIBLE_ACTION_SKIPPED = 'SKIPPED' ANSIBLE_ACTION_FINISH = 'FINISH' # Ansible TYPE ANSIBLE_TYPE_PLAYBOOK = 'PLAYBOOK' ANSIBLE_TYPE_PLAY = 'PLAY' ANSIBLE_TYPE_TASK = 'TASK' ANSIBLE_TYPE_TASK_ASYNC = 'TASK ASYNC' ANSIBLE_TYPE_IMPORT = 'IMPORT' # Ansible STATUS ANSIBLE_STATUS_OK = 'OK' ANSIBLE_STATUS_FAILED = 'FAILED' ANSIBLE_STATUS_SKIPPED = 'SKIPPED' ANSIBLE_STATUS_IMPORTED = 'IMPORTED' ANSIBLE_STATUS_NOT_IMPORTED = 'NOT IMPORTED' ANSIBLE_STATUS_UNREACHABLE = 'UNREACHABLE' # Ansible TASK TYPE ANSIBLE_TTYPE_SETUP = 'setup' # deprecated ANSIBLE_TTYPE_GATHERING_FACTS = 'Gathering Facts' ANSIBLE_TTYPE_TASK = 'task' ANSIBLE_TTYPE_INCLUDE = 'include' # deprecated # Ansible RESULT ANSIBLE_RESULT_CHANGED = 'changed' def v2_playbook_on_start(self, playbook): self.ansible_playbook_id = str(uuid.uuid1()) self.ansible_playbook_time_start = datetime.utcnow() if playbook._file_name: self.ansible_playbook_name = playbook._file_name data = self.base_data.copy() data['ansible_time_start'] = self.ansible_playbook_time_start data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_PLAYBOOK data['ansible_action'] = CallbackModule.ANSIBLE_ACTION_START data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_OK data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_playbook_file_name'] = playbook._file_name if self._es_server_is_up: self._logger.info("START PLAYBOOK | " + data['ansible_playbook_file_name'], extra=data) def v2_playbook_on_play_start(self, play): self.ansible_play_id = str(play._uuid) if play.name: self.ansible_play_name = play.name def v2_playbook_on_task_start(self, task, is_conditional): self.ansible_task_id = str(task._uuid) self.ansible_task_time_start = datetime.utcnow() if task.name: self.ansible_task_name = task.name data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK data['ansible_action'] = CallbackModule.ANSIBLE_ACTION_START data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_OK data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name if self._es_server_is_up: if self.ansible_task_name != CallbackModule.ANSIBLE_TTYPE_GATHERING_FACTS and "Include" not in self.ansible_task_name: self._logger.info("START TASK | " + data['ansible_task_name'], extra=data) def v2_playbook_on_stats(self, stats): summarize_stat = {} for host in stats.processed.keys(): summarize_stat[host] = stats.summarize(host) data = self.base_data.copy() data['ansible_time_start'] = self.ansible_playbook_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_PLAYBOOK data['ansible_action'] = CallbackModule.ANSIBLE_ACTION_FINISH if self.errors == 0: data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_OK else: data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_FAILED data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_playbook_result'] = json.dumps(summarize_stat) if self._es_server_is_up: self._logger.info("FINISH PLAYBOOK | " + data['ansible_playbook_result'], extra=data) ########################################################################### # Runner ########################################################################### def v2_runner_on_ok(self, result, **kwargs): ttype = str(result._task).replace('TASK: ', '').replace('HANDLER: ', '') data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK data['ansible_action'] = CallbackModule.ANSIBLE_ACTION_FINISH data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_OK data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name data['ansible_task_host'] = result._host.name if ttype != CallbackModule.ANSIBLE_TTYPE_GATHERING_FACTS: data['ansible_task_type'] = CallbackModule.ANSIBLE_TTYPE_TASK if CallbackModule.ANSIBLE_RESULT_CHANGED in result._result.keys(): data['ansible_task_changed'] = result._result['changed'] else: data['ansible_task_changed'] = False data['ansible_task_result'] = self._dump_results(result._result) if self._es_server_is_up: if 'include' not in data['ansible_task_result']: self._logger.info("TASK OK | " + data['ansible_task_name'] + " | RESULT | " + data['ansible_task_result'], extra=data) def v2_runner_on_skipped(self, result, **kwargs): data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK data['ansible_action'] = CallbackModule.ANSIBLE_ACTION_SKIPPED data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_OK data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name data['ansible_task_host'] = result._host.name data['ansible_task_result'] = self._dump_results(result._result) if self._es_server_is_up: if 'Include' not in data['ansible_task_name']: self._logger.info("TASK SKIPPED | " + data['ansible_task_name'], extra=data) def v2_runner_on_failed(self, result, **kwargs): data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_FAILED data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name data['ansible_task_host'] = result._host.name data['ansible_task_result'] = self._dump_results(result._result) data['ansible_task_error'] = True if CallbackModule.ANSIBLE_RESULT_CHANGED in result._result.keys(): data['ansible_task_changed'] = result._result['changed'] else: data['ansible_task_changed'] = False self.errors += 1 if self._es_server_is_up: self._logger.error("TASK FAILED | " + data['ansible_task_name'] + " | HOST | " + data['ansible_task_host'] + " | RESULT | " + data['ansible_task_result'], extra=data) def v2_runner_on_unreachable(self, result, **kwargs): data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_UNREACHABLE data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name data['ansible_task_host'] = result._host.name data['ansible_task_result'] = self._dump_results(result._result) data['ansible_task_error'] = True self.errors += 1 if self._es_server_is_up: self._logger.error("UNREACHABLE | " + data['ansible_task_name'] + " | HOST | " + data['ansible_task_host'] + " | RESULT | " + data['ansible_task_result'], extra=data) def v2_runner_on_async_failed(self, result, **kwargs): data = self.base_data.copy() data['ansible_time_start'] = self.ansible_task_time_start data['ansible_time_end'] = datetime.utcnow() data['ansible_time_duration'] = self._get_time_diff( data['ansible_time_start'], data['ansible_time_end']) data['ansible_type'] = CallbackModule.ANSIBLE_TYPE_TASK_ASYNC data['ansible_status'] = CallbackModule.ANSIBLE_STATUS_FAILED data['ansible_playbook_id'] = self.ansible_playbook_id data['ansible_playbook_name'] = self.ansible_playbook_name data['ansible_play_id'] = self.ansible_play_id data['ansible_play_name'] = self.ansible_play_name data['ansible_task_id'] = self.ansible_task_id data['ansible_task_name'] = self.ansible_task_name data['ansible_task_host'] = result._host.name data['ansible_task_result'] = self._dump_results(result._result) data['ansible_task_error'] = True self.errors += 1 if self._es_server_is_up: self._logger.error("TASK ASYNC FAILED | " + data['ansible_task_name'] + " | HOST | " + data['ansible_task_host'] + " | RESULT | " + data['ansible_task_result'], extra=data) ########################################################################### # Elastic ########################################################################### def _initialize_logger(self): # initialize handler self.handler = CMRESHandler( hosts=[{ 'host': self._get_option('host'), 'port': self._get_option('port') }], auth_details=(self._get_option('username'), self._get_option('password')), auth_type=CMRESHandler.AuthType(self._get_option('auth_type')), use_ssl=self._get_option('use_ssl'), verify_ssl=self._get_option('verify_ssl'), es_index_name=self._get_option('es_index_name'), es_additional_fields={ 'app': self._get_option('app'), 'env': self._get_option('env') }, raise_on_indexing_exceptions=self._get_option( 'raise_on_indexing_exceptions')) # check if elastic server is up self._es_server_is_up = self.handler.test_es_source() # initialize logger self._logger = logging.getLogger(self._get_option('es_logger_name')) # FIXME self._logger.setLevel(self._get_option('es_logger_level')) self._logger.setLevel(logging.DEBUG) self._logger.addHandler(self.handler) # self.ansible_session = str(uuid.uuid1()) self.ansible_version = os.popen("ansible --version | head -1").read() self.errors = 0 self.base_data = { 'ansible_global_session': self.ansible_session, 'ansible_global_version': self.ansible_version } # self.options = {} if cli: self._options = cli.options self.base_data['ansible_global_checkmode'] = self._options.check self.base_data['ansible_global_tags'] = self._options.tags self.base_data[ 'ansible_global_skip_tags'] = self._options.skip_tags self.base_data[ 'ansible_global_inventory'] = self._options.inventory def _get_time_diff(self, time_start, time_end): time_duration = relativedelta(time_end, time_start) return '{h}h {m}m {s}s'.format(h=time_duration.hours, m=time_duration.minutes, s=time_duration.seconds) ########################################################################### # Configurations ########################################################################### def _get_option(self, option): return self._config_data.get(option) def _read_config_data(self, path): ''' validate config and set options as appropriate :arg path: path to common yaml format config file for this plugin ''' config = {} try: # avoid loader cache so meta: refresh_inventory can pick up config changes # if we read more than once, fs cache should be good enough config = self.loader.load_from_file(path, cache=False) except Exception as e: raise AnsibleParserError(to_native(e)) if not config: # no data raise AnsibleParserError("%s is empty" % (to_native(path))) elif config.get('plugin') != self.NAME: # this is not my config file raise AnsibleParserError("Incorrect plugin name in file: %s" % config.get('plugin', 'none found')) elif not isinstance(config, Mapping): # configs are dictionaries raise AnsibleParserError( 'inventory source has invalid structure, it should be a dictionary, got: %s' % type(config)) return config def _get_config_file_name(self): ''' get the configuration file name ''' path = os.path.dirname(os.path.abspath(__file__)) file_name = None for filename in glob.glob(path + "/*." + self.NAME + ".yml"): file_name = filename if file_name == None: for filename in glob.glob(path + "/*." + self.NAME + ".yaml"): file_name = filename return file_name