Python logging.logger() Examples

def _get_panoptes_logger(self):
        """
        Returns the logger to be used by the context

        The method attempts to guess the name of the calling module based on introspection of the stack

        Returns:
            logger(logger): A Python logger subsystem logger

        Raises:
            PanoptesContextError: This exception is raised is any errors happen trying to instantiate the logger
        """
        self.__logger.info(u'Attempting to get logger')
        try:
            module = get_calling_module_name()
            logger = self.__rootLogger.getChild(module)
            self.__logger.info(u'Got logger for module %s' % module)
            return logger
        except Exception as e:
            raise PanoptesContextError(u'Could not get logger: %s' % str(e)) 

def exception_log(logger, head_msg, ex, level=logging.ERROR):
    """Helper to dump exception in the logger

    Parameters
    ----------
    logger: logging.logger
        the logger
    head_msg: string
        a human friendly message to prefix the exception stacktrace
    ex: Exception
        the exception
    level: type
        The wanted level (ERROR by default)

    """
    logger.log(level, "%s:" % head_msg)
    logger.log(level, "<br />".join(traceback.format_exception(etype=type(ex), value=ex, tb=ex.__traceback__)))


###############################################################################
# Callbacks
############################################################################### 

def new_result(self, job, update_model=True):
		"""
		registers finished runs

		Every time a run has finished, this function should be called
		to register it with the result logger. If overwritten, make
		sure to call this method from the base class to ensure proper
		logging.


		Parameters
		----------
		job: instance of hpbandster.distributed.dispatcher.Job
			contains all necessary information about the job
		update_model: boolean
			determines whether a model inside the config_generator should be updated
		"""
		if not job.exception is None:
			self.logger.warning("job {} failed with exception\n{}".format(job.id, job.exception)) 

def __init__(self, logger=None):
		"""
		Parameters
		----------

		directory: string
			where the results are logged
		logger: hpbandster.utils.result_logger_v??
			the logger to store the data, defaults to v1
		overwrite: bool
			whether or not existing data will be overwritten
		logger: logging.logger
			for some debug output

		"""

		if logger is None:
			self.logger=logging.getLogger('hpbandster')
		else:
			self.logger=logger 

def job_callback(self, job):
		"""
		method to be called when a job has finished

		this will do some book keeping and call the user defined
		new_result_callback if one was specified
		"""
		self.logger.debug('job_callback for %s started'%str(job.id))
		with self.thread_cond:
			self.logger.debug('job_callback for %s got condition'%str(job.id))
			self.num_running_jobs -= 1

			if not self.result_logger is None:
				self.result_logger(job)
			self.iterations[job.id[0]].register_result(job)
			self.config_generator.new_result(job)

			if self.num_running_jobs <= self.job_queue_sizes[0]:
				self.logger.debug("HBMASTER: Trying to run another job!")
				self.thread_cond.notify()

		self.logger.debug('job_callback for %s finished'%str(job.id)) 

def wait_for_workers(self, min_n_workers=1):
		"""
		helper function to hold execution until some workers are active

		Parameters
		----------
		min_n_workers: int
			minimum number of workers present before the run starts		
		"""
	
		self.logger.debug('wait_for_workers trying to get the condition')
		with self.thread_cond:
			while (self.dispatcher.number_of_workers() < min_n_workers):
				self.logger.debug('HBMASTER: only %i worker(s) available, waiting for at least %i.'%(self.dispatcher.number_of_workers(), min_n_workers))
				self.thread_cond.wait(1)
				self.dispatcher.trigger_discover_worker()
				
		self.logger.debug('Enough workers to start this run!') 

def _timed(_logger=None, level="info"):
    """
    Output execution time of a function to the given logger level

    level : str
        On which level to log the performance measurement
    Returns
    -------
    fun_wrapper : Callable
    """

    def fun_wrapper(f):
        @functools.wraps(f)
        def wraps(*args, **kwargs):
            with _timer(f.__name__, _logger=logger, level=level):
                results = f(*args, **kwargs)
            return results

        return wraps

    return fun_wrapper 

def _timer(name, _logger=None, level="info"):
    """
    Output execution time of a function to the given logger level

    Parameters
    ----------
    name : str
        How to name the timer (will be in the logs)
    logger : logging.logger
        The optional logger where to write
    level : str
        On which level to log the performance measurement
    """
    start = tic()
    _logger = _logger or logger
    _logger.info("Starting %s", name)
    yield
    stop = tic()
    delta = datetime.timedelta(seconds=stop - start)
    _logger_level = getattr(_logger, level)
    _logger_level("Finished %s in %s", name, delta)  # nicer formatting for time. 

def new_result(self, job, update_model=True):
		"""
		registers finished runs

		Every time a run has finished, this function should be called
		to register it with the result logger. If overwritten, make
		sure to call this method from the base class to ensure proper
		logging.


		Parameters
		----------
		job: instance of hpbandster.distributed.dispatcher.Job
			contains all necessary information about the job
		update_model: boolean
			determines whether a model inside the config_generator should be updated
		"""
		if not job.exception is None:
			self.logger.warning("job {} failed with exception\n{}".format(job.id, job.exception)) 

def __init__(self, logger=None):
		"""
		Parameters
		----------

		directory: string
			where the results are logged
		logger: hpbandster.utils.result_logger_v??
			the logger to store the data, defaults to v1
		overwrite: bool
			whether or not existing data will be overwritten
		logger: logging.logger
			for some debug output

		"""

		if logger is None:
			self.logger=logging.getLogger('hpbandster')
		else:
			self.logger=logger 

def job_callback(self, job):
		"""
		method to be called when a job has finished

		this will do some book keeping and call the user defined
		new_result_callback if one was specified
		"""
		self.logger.debug('job_callback for %s started'%str(job.id))
		with self.thread_cond:
			self.logger.debug('job_callback for %s got condition'%str(job.id))
			self.num_running_jobs -= 1

			if not self.result_logger is None:
				self.result_logger(job)
			self.iterations[job.id[0]].register_result(job)
			self.config_generator.new_result(job)

			if self.num_running_jobs <= self.job_queue_sizes[0]:
				self.logger.debug("HBMASTER: Trying to run another job!")
				self.thread_cond.notify()

		self.logger.debug('job_callback for %s finished'%str(job.id)) 

def wait_for_workers(self, min_n_workers=1):
		"""
		helper function to hold execution until some workers are active

		Parameters
		----------
		min_n_workers: int
			minimum number of workers present before the run starts		
		"""
	
		self.logger.debug('wait_for_workers trying to get the condition')
		with self.thread_cond:
			while (self.dispatcher.number_of_workers() < min_n_workers):
				self.logger.debug('HBMASTER: only %i worker(s) available, waiting for at least %i.'%(self.dispatcher.number_of_workers(), min_n_workers))
				self.thread_cond.wait(1)
				self.dispatcher.trigger_discover_worker()
				
		self.logger.debug('Enough workers to start this run!') 

def attach(self, engine: Engine):
        """
        Register a set of Ignite Event-Handlers to a specified Ignite engine.

        Args:
            engine: Ignite Engine, it can be a trainer, validator or evaluator.

        """
        if self._name is None:
            self.logger = engine.logger
        if not engine.has_event_handler(self.iteration_completed, Events.ITERATION_COMPLETED):
            engine.add_event_handler(Events.ITERATION_COMPLETED, self.iteration_completed)
        if not engine.has_event_handler(self.epoch_completed, Events.EPOCH_COMPLETED):
            engine.add_event_handler(Events.EPOCH_COMPLETED, self.epoch_completed)
        if not engine.has_event_handler(self.exception_raised, Events.EXCEPTION_RAISED):
            engine.add_event_handler(Events.EXCEPTION_RAISED, self.exception_raised) 

def _logAndRaiseException(self, e):
        """
        Logs an exception at log level `critical` before raising it.
        
        # Arguments
        e (Exception): The exception to log/raise
        """
        self.logger.critical(str(e))
        raise e 

def exception_raised(self, engine: Engine, e):
        """
        Handler for train or validation/evaluation exception raised Event.
        Print the exception information and traceback.

        Args:
            engine: Ignite Engine, it can be a trainer, validator or evaluator.
            e (Exception): the exception caught in Ignite during engine.run().

        """
        self.logger.exception(f"Exception: {e}")
        # import traceback
        # traceback.print_exc() 

def shutdown(self, shutdown_workers=False):
		self.logger.debug('HBMASTER: shutdown initiated, shutdown_workers = %s'%(str(shutdown_workers)))
		self.dispatcher.shutdown(shutdown_workers)
		self.dispatcher_thread.join() 

def adjust_queue_size(self, number_of_workers=None):

		self.logger.debug('HBMASTER: number of workers changed to %s'%str(number_of_workers))
		with self.thread_cond:
			self.logger.debug('adjust_queue_size: lock accquired')
			if self.dynamic_queue_size:
				nw = self.dispatcher.number_of_workers() if number_of_workers is None else number_of_workers
				self.job_queue_sizes = (self.user_job_queue_sizes[0] + nw, self.user_job_queue_sizes[1] + nw)
				self.logger.info('HBMASTER: adjusted queue size to %s'%str(self.job_queue_sizes))
			self.thread_cond.notify_all() 

def attach(self, engine: Engine):
        if self._name is None:
            self.logger = engine.logger
        if not engine.has_event_handler(self, Events.ITERATION_COMPLETED):
            engine.add_event_handler(Events.ITERATION_COMPLETED, self)
        if not engine.has_event_handler(self.saver.finalize, Events.COMPLETED):
            engine.add_event_handler(Events.COMPLETED, lambda engine: self.saver.finalize()) 

def _submit_job(self, config_id, config, budget):
		"""
		hidden function to submit a new job to the dispatcher

		This function handles the actual submission in a
		(hopefully) thread save way
		"""
		self.logger.debug('HBMASTER: trying submitting job %s to dispatcher'%str(config_id))
		with self.thread_cond:
			self.logger.debug('HBMASTER: submitting job %s to dispatcher'%str(config_id))
			self.dispatcher.submit_job(config_id, config=config, budget=budget, working_directory=self.working_directory)
			self.num_running_jobs += 1

		#shouldn't the next line be executed while holding the condition?
		self.logger.debug("HBMASTER: job %s submitted to dispatcher"%str(config_id)) 

def load_nameserver_credentials(self, working_directory, num_tries=60, interval=1):
		"""
		loads the nameserver credentials in cases where master and workers share a filesystem

		Parameters
		----------
			working_directory: str
				the working directory for the HPB run (see master)
			num_tries: int
				number of attempts to find the file (default 60)
			interval: float
				waiting period between the attempts
		"""
		fn = os.path.join(working_directory, 'HPB_run_%s_pyro.pkl'%self.run_id)
		
		for i in range(num_tries):
			try:
				with open(fn, 'rb') as fh:
					self.nameserver, self.nameserver_port = pickle.load(fh)
				return
			except FileNotFoundError:
				self.logger.warning('config file %s not found (trail %i/%i)'%(fn, i+1, num_tries))
				time.sleep(interval)
			except:
				raise
		raise RuntimeError("Could not find the nameserver information, aborting!") 

def start_computation(self, callback, id, *args, **kwargs):

		with self.thread_cond:
			while self.busy:
				self.thread_cond.wait()
			self.busy = True
		if not self.timeout is None and not self.timer is None:
			self.timer.cancel()
		self.logger.info('WORKER: start processing job %s'%str(id))
		self.logger.debug('WORKER: args: %s'%(str(args)))
		self.logger.debug('WORKER: kwargs: %s'%(str(kwargs)))
		try:
			result = {'result': self.compute(*args, config_id=id, **kwargs),
						'exception' : None}
		except Exception as e:
			result = {'result': None,
						'exception' : traceback.format_exc()}
		finally:
			self.logger.debug('WORKER: done with job %s, trying to register it.'%str(id))
			with self.thread_cond:
				self.busy =  False
				callback.register_result(id, result)
				self.thread_cond.notify()
		self.logger.info('WORKER: registered result for job %s with dispatcher'%str(id))
		if not self.timeout is None:
			self.timer = threading.Timer(self.timeout, self.shutdown)
			self.timer.daemon=True
			self.timer.start()
		return(result) 

def __init__(
        self,
        output_dir: str = "./",
        filename: str = "predictions.csv",
        overwrite: bool = True,
        batch_transform: Callable = lambda x: x,
        output_transform: Callable = lambda x: x,
        name: Optional[str] = None,
    ):
        """
        Args:
            output_dir: output CSV file directory.
            filename: name of the saved CSV file name.
            overwrite: whether to overwriting existing CSV file content. If we are not overwriting,
                then we check if the results have been previously saved, and load them to the prediction_dict.
            batch_transform: a callable that is used to transform the
                ignite.engine.batch into expected format to extract the meta_data dictionary.
            output_transform: a callable that is used to transform the
                ignite.engine.output into the form expected model prediction data.
                The first dimension of this transform's output will be treated as the
                batch dimension. Each item in the batch will be saved individually.
            name: identifier of logging.logger to use, defaulting to `engine.logger`.

        """
        self.saver = CSVSaver(output_dir, filename, overwrite)
        self.batch_transform = batch_transform
        self.output_transform = output_transform

        self.logger = None if name is None else logging.getLogger(name)
        self._name = name 

def logger(self):
        """
        A module-aware logger which will try and guess the right name for the calling module

        Returns:
            logging.logger

        """
        return self.__logger 

def play(self):
        # TODO: find python method for this,
        # sox usage for windows probably difficult . done

        import tempfile

        # get the current selection
        (st, end) = plt.gca().get_xlim()
        st = np.max([0, st])
        self.logger.debug(st, end)
        st /= PLOT_SR
        end /= PLOT_SR

        # save to tempfile
        # FIXME: cuts from the end?
        wav_slice = self.sig[int(st*self.orig_sr):int(end*self.orig_sr)]
        fname = tempfile.mkstemp()[1]
        misc.write_wav(fname, wav_slice, self.orig_sr)

        # FIXME: QSound.play used to fail silently on some systems
        try:
            QtMultimedia.QSound.play(fname)
        except Exception as ex:
            exception_log(self.logger, "Qsound does not play (use play command instead)", ex, logging.DEBUG)
            os.system("play " + fname)

    # main function
    # analysis and plotting of acoustic features and wavelets + loma 

def connect(self):
        """
        Connect the client to IBM Watson IoT Platform using the underlying Paho MQTT client
        
        # Raises
        ConnectionException: If there is a problem establishing the connection.
        """
        self.logger.debug(
            "Connecting... (address = %s, port = %s, clientId = %s, username = %s)"
            % (self.address, self.port, self.clientId, self.username)
        )
        try:
            self.connectEvent.clear()
            self.logger.debug(
                "Connecting with clientId %s to host %s on port %s with keepAlive set to %s"
                % (self.clientId, self.address, self.port, self.keepAlive)
            )
            self.logger.debug("User-Agent: %s" % self.userAgent)
            self.client.connect(self.address, port=self.port, keepalive=self.keepAlive)
            self.client.loop_start()
            if not self.connectEvent.wait(timeout=60):
                self.client.loop_stop()
                self._logAndRaiseException(
                    ConnectionException(
                        "Operation timed out connecting to IBM Watson IoT Platform: %s" % (self.address)
                    )
                )

        except socket.error as serr:
            self.client.loop_stop()
            self._logAndRaiseException(
                ConnectionException("Failed to connect to IBM Watson IoT Platform: %s - %s" % (self.address, str(serr)))
            ) 

def disconnect(self):
        """
        Disconnect the client from IBM Watson IoT Platform
        """
        # self.logger.info("Closing connection to the IBM Watson IoT Platform")
        self.client.disconnect()
        # If we don't call loop_stop() it appears we end up with a zombie thread which continues to process
        # network traffic, preventing any subsequent attempt to reconnect using connect()
        self.client.loop_stop()
        self.logger.info("Closed connection to the IBM Watson IoT Platform") 

def _onLog(self, mqttc, obj, level, string):
        """
        Called when the client has log information.  
        
        See [paho.mqtt.python#on_log](https://github.com/eclipse/paho.mqtt.python#on_log) for more information
        
        # Parameters
        mqttc (paho.mqtt.client.Client): The client instance for this callback
        obj (object): The private user data as set in Client() or user_data_set()
        level (int): The severity of the message, will be one of `MQTT_LOG_INFO`, 
            `MQTT_LOG_NOTICE`, `MQTT_LOG_WARNING`, `MQTT_LOG_ERR`, and `MQTT_LOG_DEBUG`.
        string (string): The log message itself
        
        """
        self.logger.debug("%d %s" % (level, string)) 

def _onSubscribe(self, mqttc, userdata, mid, grantedQoS):
        self.subscriptionsAcknowledged.set()
        self.logger.debug("Subscribe callback: mid: %s qos: %s" % (mid, grantedQoS))
        if self.subscriptionCallback:
            self.subscriptionCallback(mid, grantedQoS) 

def _subscribe(self, topic, qos=1):
        if not self.connectEvent.wait(timeout=10):
            self.logger.warning("Unable to subscribe to %s because client is in disconnected state" % (topic))
            return 0
        else:
            (result, mid) = self.client.subscribe(topic, qos=qos)
            if result == paho.MQTT_ERR_SUCCESS:
                with self._subLock:
                    self._subscriptions[topic] = qos
                return mid
            else:
                return 0 

def _publishEvent(self, topic, event, msgFormat, data, qos=0, onPublish=None):
        if not self.connectEvent.wait(timeout=10):
            self.logger.warning("Unable to send event %s because client is is disconnected state", event)
            return False
        else:
            if self.logger.isEnabledFor(logging.DEBUG):
                # The data object may not be serializable, e.g. if using a custom binary format
                try:
                    dataString = json.dumps(data)
                except:
                    dataString = str(data)
                self.logger.debug("Sending event %s with data %s" % (event, dataString))

            # Raise an exception if there is no codec for this msgFormat
            if self.getMessageCodec(msgFormat) is None:
                raise MissingMessageEncoderException(msgFormat)

            payload = self.getMessageCodec(msgFormat).encode(data, datetime.now(pytz.timezone("UTC")))

            result = self.client.publish(topic, payload=payload, qos=qos, retain=False)
            if result[0] == paho.MQTT_ERR_SUCCESS:
                # Because we are dealing with aync pub/sub model and callbacks it is possible that
                # the _onPublish() callback for this mid is called before we obtain the lock to place
                # the mid into the _onPublishCallbacks list.
                #
                # _onPublish knows how to handle a scenario where the mid is not present (no nothing)
                # in this scenario we will need to invoke the callback directly here, because at the time
                # the callback was invoked the mid was not yet in the list.
                with self._messagesLock:
                    if result[1] in self._onPublishCallbacks:
                        # Paho callback beat this thread so call callback inline now
                        del self._onPublishCallbacks[result[1]]
                        if onPublish is not None:
                            onPublish()
                    else:
                        # This thread beat paho callback so set up for call later
                        self._onPublishCallbacks[result[1]] = onPublish
                return True
            else:
                return False