Delay task logs

configs/config.json.example

@@ -169,7 +169,8 @@
           "enabled": true,
           "lure_attraction": true,
           "lure_max_distance": 2000,
-          "walker": "StepWalker"
+          "walker": "StepWalker",
+          "log_delay": 5
         }
       },
       {

configs/config.json.map.example

@@ -400,7 +400,8 @@
         "config": {
             "enabled": true,
             "lure_attraction": true,
-            "lure_max_distance": 2000
+            "lure_max_distance": 2000,
+            "log_delay": 5
         }
       },
       {

configs/config.json.optimizer.example

@@ -215,7 +215,8 @@
         "config": {
             "enabled": true,
             "lure_attraction": true,
-            "lure_max_distance": 2000
+            "lure_max_distance": 2000,
+            "log_delay": 5
         }
       },
       {

configs/config.json.pokemon.example

@@ -153,7 +153,8 @@
         "config":{
           "enabled": true,
           "lure_attraction": true,
-          "lure_max_distance": 2000
+          "lure_max_distance": 2000,
+          "log_delay": 5
         }
       },
       {

pokemongo_bot/base_task.py

@@ -1,5 +1,7 @@
 import logging
 
+import time
+
 
 class BaseTask(object):
   TASK_API_VERSION = 1
@@ -17,6 +19,7 @@ def __init__(self, bot, config):
     self._validate_work_exists()
     self.logger = logging.getLogger(type(self).__name__)
     self.enabled = config.get('enabled', True)
+    self.last_log_time = time.time()
     self.initialize()
 
   def _validate_work_exists(self):
@@ -27,13 +30,17 @@ def _validate_work_exists(self):
   def emit_event(self, event, sender=None, level='info', formatted='', data={}):
     if not sender:
       sender=self
-    self.bot.event_manager.emit(
-      event,
-      sender=sender,
-      level=level,
-      formatted=formatted,
-      data=data
-    )
+
+    # Print log only if X seconds are passed from last log
+    if (time.time() - self.last_log_time) > self.config.get('log_delay', 0):
+      self.last_log_time = time.time()
+      self.bot.event_manager.emit(
+        event,
+        sender=sender,
+        level=level,
+        formatted=formatted,
+        data=data
+      )
 
   def initialize(self):
     pass

pokemongo_bot/test/log_delay_test.py

@@ -0,0 +1,62 @@
+import unittest
+from datetime import timedelta, datetime
+from time import sleep
+
+from mock import patch, MagicMock
+
+from pokemongo_bot.cell_workers import MoveToFort
+from tests import FakeBot
+
+
+class LogDelayTestCase(unittest.TestCase):
+
+    config = {
+          "enabled": 'true',
+          "lure_attraction": 'true',
+          "lure_max_distance": 2000,
+          "walker": "StepWalker",
+          "log_delay": 3
+      }
+
+    def setUp(self):
+        self.bot = FakeBot()
+        self.bot.event_manager = MagicMock()
+        self.worker = MoveToFort(self.bot, self.config)
+
+    def test_read_correct_delay_config(self):
+        self.worker.config['log_delay'] = 3
+        self.assertEqual(self.config.get('log_delay'), 3)
+
+    def test_log_with_no_delay(self):
+        self.worker.config['log_delay'] = 3
+        # All those call should not happen cause without any delay between each other
+        self.worker.emit_event('moving_to_fort', formatted="just an example")
+        self.worker.emit_event('moving_to_fort', formatted="just an example")
+
+        # Let's try to subtract 2 of 3 sec and see if event_manager.emit() get no call at all
+        self.worker.last_log_time -= 2
+        self.worker.emit_event('moving_to_fort', formatted="just an example")
+        self.worker.emit_event('moving_to_fort', formatted="just an example")
+
+        self.assertEqual(self.bot.event_manager.emit.call_count, 0)
+        assert not self.bot.event_manager.emit.called
+
+    def test_correct_delay_wait(self):
+
+        self.worker.config['log_delay'] = 2
+
+        # to avoid use sleep() function here, we subtract expected log_delay to last_log_time
+        self.worker.last_log_time -= self.worker.config['log_delay']
+
+        for number_of_checks in range(10):
+            self.worker.emit_event('moving_to_fort', formatted="just an example")
+            self.worker.last_log_time -= 2
+
+        self.assertEqual(self.bot.event_manager.emit.call_count, 10)
+
+        # i think should be better assert in this way, but can't get it working
+        # assert self.bot.event_manager.emit.assert_any_call('moving_to_fort',
+        #                                                    sender=None,
+        #                                                    level='info',
+        #                                                    formatted="just an example",data={})
+