diff --git a/sarracenia/flow/__init__.py b/sarracenia/flow/__init__.py index 64e0f5809..8c2ee7a5b 100644 --- a/sarracenia/flow/__init__.py +++ b/sarracenia/flow/__init__.py @@ -243,7 +243,7 @@ def loadCallbacks(self, plugins_to_load=None): logger.debug( "details:", exc_info=True ) return False - logger.info( f'flowCallback plugins to load: {plugins_to_load}' ) + logger.debug( f'flowCallback plugins to load: {plugins_to_load}' ) for c in plugins_to_load: try: plugin = sarracenia.flowcb.load_library(c, self.o) @@ -301,7 +301,6 @@ def runCallbacksTime(self, entry_point): eval( f"self.{entry_point}()") else: try: - logger.info( f'normal run of self.{entry_point}' ) eval( f"self.{entry_point}()") except Exception as ex: logger.error( f'flow {entry_point} crashed: {ex}' ) @@ -446,9 +445,7 @@ def reject(self, m, code, reason) -> None: m.setReport(code, reason) def please_stop(self) -> None: - logger.info( - f'ok, telling {len(self.plugins["please_stop"])} callbacks about it.' - ) + logger.info( f'ok, telling {len(self.plugins["please_stop"])} callbacks about it.') self._stop_requested = True self.metrics["flow"]['stop_requested'] = True @@ -528,8 +525,8 @@ def run(self): logger.debug("options:") self.o.dump() - logger.info("callbacks loaded: %s" % self.plugins['load']) - logger.info( + logger.debug("callbacks loaded: %s" % self.plugins['load']) + logger.debug( f'pid: {os.getpid()} {self.o.component}/{self.o.config} instance: {self.o.no}' ) @@ -541,11 +538,11 @@ def run(self): if self._stop_requested: if stopping: - logger.info('clean stop from run loop') + logger.debug('clean stop from run loop') self.close() break else: - logger.info( 'starting last pass (without gather) through loop for cleanup.') + logger.debug( 'starting last pass (without gather) through loop for cleanup.') stopping = True self._run_vip_update() @@ -598,7 +595,7 @@ def run(self): if (last_gather_len == 0) and (self.o.sleep < 0): if (self.o.retryEmptyBeforeExit and "retry" in self.metrics and self.metrics['retry']['msgs_in_post_retry'] > 0): - logger.info("Not exiting because there are still messages in the post retry queue.") + logger.debug("Not exiting because there are still messages in the post retry queue.") # Sleep for a while. Messages can't be retried before housekeeping has run... current_sleep = 60 else: @@ -621,7 +618,7 @@ def run(self): self.o.messageRateMax): stime = 1 + 2 * ((current_rate - self.o.messageRateMax) / self.o.messageRateMax) - logger.info( + logger.debug( "current_rate/2 (%.2f) above messageRateMax(%.2f): throttling" % (current_rate, self.o.messageRateMax)) else: @@ -1110,7 +1107,7 @@ def gather(self) -> None: return if len(self.worklist.incoming) > 0: - logger.info('ingesting %d postings into duplicate suppression cache' % len(self.worklist.incoming) ) + logger.debug('ingesting %d postings into duplicate suppression cache' % len(self.worklist.incoming) ) self.worklist.poll_catching_up = True return else: @@ -1239,7 +1236,7 @@ def post(self,now) -> None: mfn.write( f'\"{timestamp}\" : {metrics},\n') # removing old metrics files - logger.info( f"looking for old metrics for {self.o.metricsFilename}" ) + logger.debug( f"looking for old metrics for {self.o.metricsFilename}" ) old_metrics=sorted(glob.glob(self.o.metricsFilename+'.*'))[0:-self.o.logRotateCount] for o in old_metrics: logger.info( f"removing old metrics file: {o} " ) @@ -1492,7 +1489,7 @@ def removeOneFile(self, path) -> bool: if os.path.isfile(path): os.unlink(path) if os.path.islink(path): os.unlink(path) if os.path.isdir(path): os.rmdir(path) - logger.info("removed %s" % path) + logger.debug("removed %s" % path) except: logger.error("could not remove %s." % path) logger.debug('Exception details: ', exc_info=True) @@ -1505,7 +1502,6 @@ def renameOneItem(self, old, path) -> bool: for messages with an rename file operation, it is to rename a file. """ ok = True - logger.info( f" pwd is {os.getcwd()} " ) if not os.path.exists(old): logger.info( "old file %s not found, if destination (%s) missing, then fall back to copy" @@ -1642,7 +1638,7 @@ def do_download(self) -> None: if not os.path.isdir(msg['new_dir']): try: - logger.info( f"missing destination directories, makedirs: {msg['new_dir']} " ) + logger.debug( f"missing destination directories, makedirs: {msg['new_dir']} " ) self.worklist.directories_ok.append(msg['new_dir']) os.makedirs(msg['new_dir'], 0o775, True) except Exception as ex: @@ -2025,7 +2021,7 @@ def download(self, msg, options) -> bool: remote_offset += msg['blocks']['manifest'][blkno]['size'] block_length=msg['blocks']['manifest'][msg['blocks']['number']]['size'] - logger.info( f"offset calculation: start={remote_offset} count={block_length}" ) + logger.debug( f"offset calculation: start={remote_offset} count={block_length}" ) elif 'size' in msg: block_length = msg['size'] diff --git a/sarracenia/flowcb/log.py b/sarracenia/flowcb/log.py index 5cd3bbf13..88f4fccd0 100755 --- a/sarracenia/flowcb/log.py +++ b/sarracenia/flowcb/log.py @@ -29,7 +29,7 @@ def __init__(self, options): self.o.add_option('logEvents', 'set', ['after_accept', 'on_housekeeping']) self.o.add_option('logMessageDump', 'flag', False) - logger.info(f'{self.o.component} initialized with: logEvents: {self.o.logEvents}, logMessageDump: {self.o.logMessageDump}') + logger.debug(f'{self.o.component} initialized with: logEvents: {self.o.logEvents}, logMessageDump: {self.o.logMessageDump}') if self.o.component in ['sender']: self.action_verb = 'sent' elif self.o.component in ['subscribe', 'sarra' ]: diff --git a/sarracenia/flowcb/nodupe/disk.py b/sarracenia/flowcb/nodupe/disk.py index ada9eeba2..76b8c72a2 100755 --- a/sarracenia/flowcb/nodupe/disk.py +++ b/sarracenia/flowcb/nodupe/disk.py @@ -56,8 +56,6 @@ def __init__(self, options): self.o.add_option( 'nodupe_ttl', 'duration', 0 ) - logger.info('time_to_live=%d, ' % (self.o.nodupe_ttl)) - self.cache_dict = {} self.cache_file = None self.cache_hit = None @@ -71,7 +69,7 @@ def __init__(self, options): def on_housekeeping(self): - logger.info("start (%d)" % len(self.cache_dict)) + logger.debug("start with %d entries)" % len(self.cache_dict)) count = self.count self.save() @@ -79,9 +77,9 @@ def on_housekeeping(self): self.now = nowflt() new_count = self.count - logger.info( - "was %d, but since %5.2f sec, increased up to %d, now saved %d entries" - % (self.last_count, self.now - self.last_time, count, new_count)) + if new_count > 0: + logger.info( "was %d, but since %5.2f sec, increased up to %d, now saved %d entries" + % (self.last_count, self.now - self.last_time, count, new_count)) self.last_time = self.now self.last_count = new_count diff --git a/sarracenia/flowcb/post/message.py b/sarracenia/flowcb/post/message.py index c04c90e06..260021941 100755 --- a/sarracenia/flowcb/post/message.py +++ b/sarracenia/flowcb/post/message.py @@ -63,9 +63,9 @@ def on_housekeeping(self): def on_start(self): if hasattr(self,'poster') and self.poster: self.poster.putSetup() - logger.info('starting') + logger.debug('starting') def on_stop(self): if hasattr(self,'poster') and self.poster: self.poster.close() - logger.info('closing') + logger.debug('closing')