Repository: seznam/flexp

Issue:
Make easier debuging why PickleCache fails to compute the same hash for the same chain.
Sometimes PickleCache computes different hash for the same chain. Adding some parameter that prints a lot of debug info about the hashes of individual component of the chain will make it easier to track where the hash computation failed.

Discussion:

Patch:
diff --git a/examples/ignore_attributes_and_debug.py b/examples/ignore_attributes_and_debug.py
new file mode 100644
index 0000000..8883a7b
--- /dev/null
+++ b/examples/ignore_attributes_and_debug.py
@@ -0,0 +1,75 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+"""
+FILE         $Id$
+AUTHOR       Ksenia Shakurova <ksenia.shakurova@firma.seznam.cz>
+
+Copyright (c) 2017 Seznam.cz, a.s.
+All rights reserved.
+"""
+import argparse
+
+import common.flow.flog as flog
+from common.flow import Chain
+from flexp import flexp
+from flexp.flow.cache import PickleCache
+
+log = flog.Log(__name__)
+
+from flexp.flow import cache
+
+
+# define module with some attributes
+class TestModule:
+    # PickleCacheBlackList will be the list
+    PickleCacheBlackList = ['attr3']
+
+    def __init__(self, attr1, attr2, attr3):
+        self.attr1 = attr1
+        self.attr2 = attr2
+        self.attr3 = attr3  # this parameter will be skipped
+
+    def process(self, data):
+        #....
+        pass
+
+
+class FlowData(object):
+
+    def __init__(self):
+        self.id = ""
+        self.attrs = [1, 2, 3]
+
+    def __iter__(self):
+        return iter(self.__dict__)
+
+    def items(self):
+        return [(attr, getattr(self, attr)) for attr in self.__dict__]
+
+    def __setitem__(self, key, item):
+        setattr(self, key, item)
+
+    def __getitem__(self, key):
+        return getattr(self, key)
+
+
+def main():
+    flexp.setup("experiments/", "exp01", False)
+
+    flog.setup("debug", path=flexp.get_file_path("experiment.log.txt"))  # , disable_stderr=not cfg.SHORT_RUN)
+    log.debug('Starting.')
+
+    data = FlowData()
+    data.id = "a"
+
+    # debug level 2 - all detailes will be printed
+    data_chain = PickleCache("cached_pkls", "id", chain=[TestModule(12, 14, 18)], debug_level=2)
+    data_chain.process(data)
+
+    # hash of this and previous are same
+    data_chain = PickleCache("cached_pkls", "id", chain=[TestModule(12, 14, 20)], debug_level=1)
+    data_chain.process(data)
+
+
+if __name__ == "__main__":
+    main()
diff --git a/flexp/flow/README.md b/flexp/flow/README.md
index 687cc42..cdfe62f 100644
--- a/flexp/flow/README.md
+++ b/flexp/flow/README.md
@@ -128,3 +128,19 @@ Solution for this is to store only the name of the database and open it in the `
     cached_chain.process({'id': file_name})
     cached_chain.close()
 ```
+
+
+PickleCache is too sensiive and takes into account all variables. You can change this behaviour by adding
+`PickleCacheBlackList` class attribute to your module:
+
+```python
+class TestModule:
+    # PickleCacheBlackList is a list with attribute names
+    PickleCacheBlackList = ['attr3']
+
+    def __init__(self, attr1, attr2, attr3):
+        self.attr1 = attr1
+        self.attr2 = attr2
+        self.attr3 = attr3
+```
+
diff --git a/flexp/flow/cache.py b/flexp/flow/cache.py
index adf758d..5ab7cfd 100644
--- a/flexp/flow/cache.py
+++ b/flexp/flow/cache.py
@@ -3,6 +3,8 @@ from __future__ import print_function
 from __future__ import absolute_import
 from __future__ import division
 
+from copy import deepcopy, copy
+
 import six
 import collections
 import time
@@ -74,12 +76,13 @@ class PickleCache(Chain, PickleMixin):
     """
 
     def __init__(self, directory, data_key="id", chain=None, force=False,
-                 max_recursion_level=10, dir_rights=0o777):
+                 max_recursion_level=10, dir_rights=0o777, debug_level=0):
         super(PickleCache, self).__init__(chain)
         self.directory = directory
         self.force = force
         self.data_key = data_key
         self.max_recursion_level = max_recursion_level
+        self.debug_level = debug_level
 
         self.chain_info = {'chain_len': 0, 'chain_hash': None,
                            'chain_mtime': None,
@@ -117,47 +120,81 @@ class PickleCache(Chain, PickleMixin):
         log.debug("Cache: {}".format(file))
         return os.path.exists(file)
 
-    def _object_dump_to_string(self, obj, level=0):
+    def _object_dump_to_string(self, obj, level=0, debug_level=0):
         """Consolidate object with its attributes and their values into ony byte-string.
+        If object has PickleCacheBlackList class attribute then attributes listed there are not taken into account.
 
         :param obj: Object instance
-        :return: unicode String image of the pickled object
+        :param int level: recursion level
+        :param int debug_level: debug_level 0 (silence), 1 or 2 (full)
+         :return: unicode String image of the pickled object
         """
         if level > self.max_recursion_level:
             return ""
+
         dump_string = obj.__class__.__name__.encode("ASCII")
+        if debug_level == 2:
+            print("\t"*level+"level: {}, class name {}".format(level, dump_string))
+
         if hasattr(obj, '__name__'):  # to distinguish functions from each other
             dump_string += obj.__name__.encode("ASCII")
+            if debug_level == 2:
+                print("\t"*level+"level: {}, function name {}".format(level, obj.__name__.encode("ASCII")))
 
         # Get insides of the objects, based on the type
-        items = []
+
         if isinstance(obj, str):
+            if debug_level == 2:
+                print("\t"*level+"level: {}, obj is str: {}".format(level, obj))
             return dump_string + obj
         else:
             try:
-                items = sorted(vars(obj).items())
+                items = copy(vars(obj))
+                if hasattr(obj, 'PickleCacheBlackList'):
+                    if debug_level == 2:
+                        print("\t"*level+"obj has blacklist", obj.PickleCacheBlackList)
+                    for v in obj.PickleCacheBlackList:
+                        del items[v]
+
+                items = sorted(items.items())
             except:
                 try:
                     items = sorted(obj.items())
                 except:
                     items = [(str(i), o) for i, o in enumerate(obj)]
 
+        if debug_level == 2:
+            print("\t"*level+"level: {}, items: {}".format(level, items))
         for attribute, value in items:
+            # TODO checkpoints
+            # TODO check for checkpoints
             try:
+                if debug_level == 2:
+                    print("\t" * level + "level: {}, attribute: {}".format(level, attribute))
                 try:
-                    dump_string += self._object_dump_to_string(attribute, level + 1)
+                    add_string = self._object_dump_to_string(attribute, level + 1, debug_level)
                 except:
-                    dump_string += self.pickle(attribute)
+                    add_string = self.pickle(attribute)
+                dump_string += add_string
             except pickle.PicklingError:  # attribute could not be dumped
                 pass
 
             try:
+                if debug_level == 2:
+                    print("\t"*level+"level: {}, value: {}".format(level, value))
                 try:
-                    dump_string += self._object_dump_to_string(value, level + 1)
+                    add_string = self._object_dump_to_string(value, level + 1, debug_level)
                 except:
-                    dump_string += self.pickle(value)
+                    add_string = self.pickle(value)
+                dump_string += add_string
             except pickle.PicklingError:  # attribute could not be dumped
                 pass
+
+        if debug_level > 0 and level == 0:
+            print("dump_string is {}\n"
+                  "Compare this with another cache hash with command\n"
+                  " $ cmp -bl <(echo -n abcda) <(echo -n aqcde)".format(hashlib.sha256(six.binary_type().join([dump_string])).hexdigest()))
+
         return dump_string
 
     def _get_chain_hash(self, chain):
@@ -167,7 +204,7 @@ class PickleCache(Chain, PickleMixin):
         :param chain: list of modules
         :return: string
         """
-        chain_string = [self._object_dump_to_string(chain)]
+        chain_string = [self._object_dump_to_string(chain, debug_level=self.debug_level)]
         return hashlib.sha256(six.binary_type().join(chain_string)).hexdigest()
 
     def _get_object_mtime(self, obj):


Test patch:
diff --git a/tests/test_cache_attrs.py b/tests/test_cache_attrs.py
new file mode 100644
index 0000000..dd096c1
--- /dev/null
+++ b/tests/test_cache_attrs.py
@@ -0,0 +1,60 @@
+from __future__ import absolute_import
+
+import os
+import pickle
+import shutil
+import unittest
+from flexp.flow import cache
+
+
+class TestModule:
+
+    PickleCacheBlackList = ['attr3']
+
+    def __init__(self, attr1, attr2, attr3):
+        self.attr1 = attr1
+        self.attr2 = attr2
+        self.attr3 = attr3
+        # self.cache_bckl = ['attr3']
+
+    def process(self, data):
+        pass
+
+
+class TestCache(unittest.TestCase):
+    """Test the hash of cache and black list parameter"""
+
+    cache_dir = "tests/cached_pkls"
+
+    def setUp(self):
+        if os.path.exists(self.cache_dir):
+            shutil.rmtree(self.cache_dir)
+
+    def tearDown(self):
+        if os.path.exists(self.cache_dir):
+            shutil.rmtree(self.cache_dir)
+
+    def test_cache(self):
+
+        c = cache.PickleCache(self.cache_dir, "input", chain=[
+            TestModule(12, 14, 18),
+        ])
+        c.process({"input": 10})
+
+        # different value for attribute from black list
+        c2 = cache.PickleCache(self.cache_dir, "input", chain=[
+            TestModule(12, 14, 20),
+        ])
+        c2.process({"input": 10})
+        self.assertEqual(c.chain_info['chain_hash'], c2.chain_info['chain_hash'])
+
+        # different value for attribute that is not in black list
+        c3 = cache.PickleCache(self.cache_dir, "input", chain=[
+            TestModule(12, 12, 18),
+        ])
+        c3.process({"input": 10})
+        self.assertFalse(c.chain_info['chain_hash'] == c3.chain_info['chain_hash'])
+
+        c.close()
+        c2.close()
+        c3.close()