Added SCHEDLOG for testing

circle/manager/scheduler.py

@@ -15,17 +15,18 @@
 # You should have received a copy of the GNU General Public License along
 # with CIRCLE.  If not, see <http://www.gnu.org/licenses/>.
 
-from logging import getLogger
+import random
+import datetime
 
+from django.core.cache import cache
 from django.utils.translation import ugettext_noop
 from django.utils import timezone
 from django.conf import settings
 
 from common.models import HumanReadableException
-
+from logging import getLogger
 from circle.settings.base import SCHEDULER_METHOD
 
-import random
 
 logger = getLogger(__name__)
 
@@ -71,7 +72,7 @@ def common_select(instance, nodes):
         logger.warning('select_node: no enough RAM for %s', unicode(instance))
         raise NotEnoughMemoryException()
 
-    # sort nodes first by sorting_key, then priority
+    # sort nodes first by priority
     nodes.sort(key=lambda n: n.priority, reverse=True)
     return nodes
 
@@ -88,12 +89,15 @@ def common_random(instance, nodes):
     result = random.choice(nodes)
     return result
 
+
 def advanced_with_time_stamp(instance, nodes):
     nodes = common_select(instance, nodes)
     nodes.sort(key=sorting_key, reverse=True)
+    logger.info('SCHEDLOG: %s', nodes)
     result = nodes[0]
     return result
 
+
 def select_node(instance, nodes):
     ''' Select a node for hosting an instance based on its requirements.
     '''
@@ -106,11 +110,10 @@ def select_node(instance, nodes):
     else:  # Default method is the random
         result = common_random(instance, nodes)
 
-    logger.info('Scheduler method: %s selected', unicode(SCHEDULER_METHOD))
-    logger.info('select_node: %s for %s', unicode(result), unicode(instance))
+    logger.info('SCHEDLOG: Scheduler method: %s selected', unicode(SCHEDULER_METHOD))
+    logger.info('SCHEDLOG: select_node: %s for %s', unicode(result), unicode(instance))
 
-    result.time_stamp = timezone.now()
-    result.save()
+    set_time_stamp(result)
 
     return result
 
@@ -124,8 +127,18 @@ def sorting_key(node):
         key = free_cpu_time(node) * corr
     else:
         key = free_ram(node) * corr
+    logger.info('SCHEDLOG: node: %s score: %s freecpu: %s freeram: %s', unicode(node), unicode(key), unicode(free_cpu_time(node)), unicode(free_ram(node)))
     return key
 
+def set_time_stamp(node):
+    cache.set('time_stamp{}'.format(node.id), timezone.now())
+
+def get_time_stamp(node):
+    time_stamp = cache.get('time_stamp{}'.format(node.id))
+    if time_stamp:
+        return time_stamp
+    return datetime.datetime(1970,1,1, tzinfo=timezone.get_current_timezone())
+
 def last_scheduled_correction_factor(node):
     """Returns the time correction factor for a node.
 
@@ -136,7 +149,7 @@ def last_scheduled_correction_factor(node):
     factor = 0
     max_time_diff = settings.SCHEDULER_TIME_SENSITIVITY_IN_SECONDS
     current_time = timezone.now()
-    time_difference_in_seconds = (current_time - node.time_stamp).total_seconds()
+    time_difference_in_seconds = (current_time - get_time_stamp(node)).total_seconds()
     factor = time_difference_in_seconds/float(max_time_diff)
     if factor > 1:
         factor = 1
@@ -145,6 +158,7 @@ def last_scheduled_correction_factor(node):
     logger.info('Scheduler set factor to %s', unicode(factor))   
     return factor
 
+
 def has_traits(traits, node):
     """True, if the node has all specified traits; otherwise, false.
     """
@@ -190,7 +204,7 @@ def free_cpu_time(node):
         weighted_value = free_cpu_percent * weight
         return weighted_value
     except TypeError as e:
-        logger.warning('Got incorrect monitoring data for node %s. %s',
+        logger.exception('Got incorrect monitoring data for node %s. %s',
                        unicode(node), unicode(e))
         return 0 # will result lowest priority