Lots of debugging/verification prints

deletionwatcher.py

@@ -53,10 +53,13 @@ def __init__(self):
         if datahandling.has_pickle(PICKLE_FILENAME):
             pickle_info = datahandling.load_pickle(PICKLE_FILENAME)
             if 'version' not in pickle_info:
+                print('Found version 1 of pickle')
                 # original pickle version
                 for post_url in DeletionWatcher._check_batch(pickle_info):
                     self.subscribe(post_url)
             elif pickle_info['version'] == '2':
+                print('Found version 2 of pickle')
+                print('pickle_info[\'posts\']:', pickle_info['posts'])
                 with self.posts_lock:
                     self.posts = pickle_info['posts']
                 self.expunge_expired_posts(False)
@@ -82,10 +85,13 @@ def _start(self):
                         if data["a"] == "post-deleted":
                             try:
                                 post_id = str(data["aId"] if "aId" in data else data["qId"])
+                                print('WebSocket shows deleted: post_id:', post_id)
                                 with self.posts_lock:
                                     _, _, _, post_url, _, _, callbacks = self.posts[action][post_id]
+                                    print('deleting: self.posts[action][post_id]:', self.posts[action][post_id])
                                     del self.posts[action][post_id]
                                     if len(self.posts[action]) == 0:
+                                        print('deleting and unsubscribing: self.posts[action]:', self.posts[action])
                                         del self.posts[action]
                                         Tasks.do(self._unsubscribe, action)
                                 Tasks.do(metasmoke.Metasmoke.send_deletion_stats_for_post, post_url, True)
@@ -104,16 +110,25 @@ def _start(self):
                 self.hb_time = None
 
     def expunge_expired_posts(self, unsubscribe=True):
+        print('expunge_expired_posts:')
         now = time.time()
         with self.posts_lock:
             actions = list(self.posts.keys())
+            print('actions:', actions)
             for action in actions:
+                print('action:', action)
                 post_ids = list(self.posts[action].keys())
+                print('post_ids:', post_ids)
                 for post_id in post_ids:
+                    print('post_id:', post_id)
+                    print('self.posts[action][post_id]:', self.posts[action][post_id])
                     _, _, _, _, _, max_time, _ = self.posts[action][post_id]
+                    print('max_time:', max_time)
                     if now > max_time:
+                        print('Deleting due to expired: self.posts[action][post_id]:', self.posts[action][post_id])
                         del self.posts[action][post_id]
                 if len(self.posts[action]) == 0:
+                    print('Deleting: self.posts[action]:', self.posts[action])
                     del self.posts[action]
                     if unsubscribe:
                         Tasks.do(self._unsubscribe, action)
@@ -161,10 +176,13 @@ def subscribe(self, post_url, callback=None, timeout=None):
             # This is fully replaced in order to update the max_watch_time
             self.posts[action][post_id] = (post_id, post_site, post_type, post_url, question_id,
                                            now + DELETION_WATCH_MIN_SECONDS, callbacks)
+            print('Subscribing to post_id:', post_id)
+            print('Subscribing to self.posts[action][post_id]:', self.posts[action][post_id])
         if needs_subscribe:
             Tasks.do(self._subscribe, action)
 
     def _subscribe(self, action):
+        print('Subscribing to action:', action)
         if self.socket:
             try:
                 self.socket.send(action)
@@ -176,20 +194,25 @@ def _subscribe(self, action):
 
     def save(self):
         # We save a copy of the self.posts data, but with the calbacks removed.
+        print('Saving DeletionWatcher pickle:')
         if GlobalVars.no_deletion_watcher:
             return
         pickle_data = {}
 
         with self.posts_lock:
             for action in self.posts:
+                print('action:', action)
+                print('self.posts[action]:', self.posts[action])
                 pickle_data[action] = {}
                 for post in self.posts[action]:
                     (post_id, post_site, post_type, post_url, question_id, max_time, _) = self.posts[action][post]
                     pickle_data[action][post] = (post_id, post_site, post_type, post_url, question_id, max_time, [])
+                print('pickle_data[action]:', pickle_data[action])
         pickle_output = {
             'version': '2',
             'posts': pickle_data,
         }
+        print('pickle_output:', pickle_output)
         datahandling.dump_pickle(PICKLE_FILENAME, pickle_output)
 
     @staticmethod