def test_basic_event_log(self): logger = logging.getLogger(__name__) filter = tracer.RequestFilter() logger.addFilter(filter) with tracer.RequestTracer("12345"): logger.error("A log record")
def kill(self): with tracer.RequestTracer(self._request_id): if self._reply_message_timer: try: self._reply_message_timer.cancel() except Exception as ex: _g_logger.info("an exception occurred when trying to " "cancel the timer: " + str(ex))
def shutdown(self): with tracer.RequestTracer(self._request_id): try: if self._reply_message_timer: self._reply_message_timer.cancel() self._reply_listener.message_done(self) except Exception as ex: _g_logger.warn("Error shutting down the request", ex)
def reply(self, response_document): """ Send a reply to this request. This signifies that the user is done with this object. """ with tracer.RequestTracer(self._request_id): _g_logger.debug("reply() has been called") self._sm.event_occurred(states.ReplyEvents.USER_REPLIES, message=response_document)
def nak(self, response_document): """ This function is called to out right reject the message. The user is signifying that this message will not be processed at all. A call to this function signifies that this object will no longer be referenced by the user. """ with tracer.RequestTracer(self._request_id): self._sm.event_occurred(states.ReplyEvents.USER_REJECTS_REQUEST, message=response_document)
def ack(self, cancel_callback, cancel_callback_args, cancel_callback_kwargs): """ Indicate to the messaging system that you have successfully received this message and stored it for processing. """ with tracer.RequestTracer(self._request_id): self._cancel_callback = cancel_callback self._cancel_callback_args = cancel_callback_args if self._cancel_callback_args is None: self._cancel_callback_args = [] self._cancel_callback_args.insert(0, self) self._cancel_callback_kwargs = cancel_callback_kwargs self._sm.event_occurred(states.ReplyEvents.USER_ACCEPTS_REQUEST, message={})
def run(self): try: _g_logger.info("Worker %s thread starting." % self.getName()) done = False while not done: try: workload = self.worker_queue.get() if workload is None: continue if workload.quit: done = True self.worker_queue.task_done() continue # setup message logging with tracer.RequestTracer(workload.request_id): reply_doc = _run_plugin(self._conf, workload.items_map, workload.request_id, workload.payload["command"], workload.payload["arguments"]) self.worker_queue.task_done() _g_logger.debug( "Adding the reply document to the reply " "queue " + str(reply_doc)) work_reply = WorkReply(workload.request_id, reply_doc) dcm_events.register_callback(self._reply_callback, args=[work_reply]) _g_logger.info("Reply message sent for command " + workload.payload["command"]) except queue.Empty: pass except: _g_logger.exception( "Something went wrong processing the queue") raise finally: _g_logger.info("Worker %s thread ending." % self.getName())
def incoming_message(self, json_doc): with tracer.RequestTracer(self._request_id): type_to_event = { message_types.MessageTypes.ACK: states.ReplyEvents.REPLY_ACK_RECEIVED, message_types.MessageTypes.NACK: states.ReplyEvents.REPLY_NACK_RECEIVED, message_types.MessageTypes.CANCEL: states.ReplyEvents.CANCEL_RECEIVED, message_types.MessageTypes.STATUS: states.ReplyEvents.STATUS_RECEIVED, message_types.MessageTypes.REQUEST: states.ReplyEvents.REQUEST_RECEIVED } if 'type' not in json_doc: raise exceptions.MissingMessageParameterException('type') if json_doc['type'] not in type_to_event: raise exceptions.InvalidMessageParameterValueException( 'type', json_doc['type']) # this next call drives the state machine self._sm.event_occurred(type_to_event[json_doc['type']], message=json_doc)
def _process_doc(self, incoming_doc): if incoming_doc is None: return with tracer.RequestTracer(incoming_doc['request_id']): self._call_reply_observers("incoming_message", incoming_doc) _g_logger.debug("New message type %s" % incoming_doc['type']) # if the agent is misbehaving the AM might tell it to kill itself. # cold. if incoming_doc["type"] == message_types.MessageTypes.HEMLOCK: _g_logger.error("HEMLOCK: DCM told me to kill myself.") os.killpg(0, signal.SIGKILL) sys.exit(10) # if it is a alert message short circuit if incoming_doc["type"] == message_types.MessageTypes.ALERT_ACK: if self._id_system: self._id_system.incoming_message(incoming_doc) return request_id = incoming_doc["request_id"] # is this request already in memory? if request_id in self._requests: _g_logger.debug("The message was found in the requests.") # send it through, state machine will deal with it req = self._requests[request_id] req.incoming_message(incoming_doc) return # if the request id has already been seen by the database db_record = self._db.lookup_req(request_id) if db_record: _g_logger.info("Inflating the record from the DB." + request_id) req = ReplyRPC( self, self._conf.agent_id, self._conn, request_id, incoming_doc, self._db, timeout=self._timeout, reply_doc=db_record.reply_doc, start_state=db_record.state) # this will probably be used in the near future so get it # on the memory list self._requests[request_id] = req req.incoming_message(incoming_doc) return if incoming_doc["type"] == message_types.MessageTypes.REQUEST: if len(list(self._requests.keys())) >=\ self._conf.messaging_max_at_once > -1: # short circuit the case where the agent is too busy dcm_logger.log_to_dcm_console_overloaded( msg="The new request was rejected because the agent has too many outstanding requests.") nack_doc = { 'type': message_types.MessageTypes.NACK, 'message_id': utils.new_message_id(), 'request_id': request_id, 'agent_id': self._conf.agent_id, 'error_message': ("The agent can only handle %d " "commands at once" % self._conf.messaging_max_at_once)} self._conn.send(nack_doc) return _g_logger.debug("A new request has come in.") req = ReplyRPC( self, self._conf.agent_id, self._conn, request_id, incoming_doc, self._db, timeout=self._timeout) self._call_reply_observers("new_message", req) # only add the message if processing was successful self._requests[request_id] = req try: self._dispatcher.incoming_request(req) except Exception: _g_logger.exception("The dispatcher could not handle a " "message.") del self._requests[request_id] dcm_logger.log_to_dcm_console_messaging_error( msg="The dispatcher could not handle the message.") raise else: # if we have never heard of the ID and this is not a new # request we return a courtesy error _g_logger.debug("Unknown message ID sending a NACK") nack_doc = {'type': message_types.MessageTypes.NACK, 'message_id': utils.new_message_id(), 'request_id': request_id, 'agent_id': self._conf.agent_id, 'error_message': "%s is an unknown ID" % request_id} self._conn.send(nack_doc)
def reply_timeout(self, message_timer): with tracer.RequestTracer(self._request_id): _g_logger.debug("reply timeout occurred, resending.") self._sm.event_occurred(states.RequesterEvents.TIMEOUT, message_timer=message_timer)