Merge pull request #5 from bookest/logging

Use timestamped logs

governor.py

@@ -1,10 +1,15 @@
 #!/usr/bin/env python
 
 import sys, os, yaml, time, urllib2, atexit
+import logging
+
 from helpers.etcd import Etcd
 from helpers.postgresql import Postgresql
 from helpers.ha import Ha
 
+
+logging.basicConfig(format='%(asctime)s %(levelname)s: %(message)s', level=logging.INFO)
+
 f = open(sys.argv[1], "r")
 config = yaml.load(f.read())
 f.close()
@@ -25,7 +30,7 @@ while not etcd_ready:
         etcd.touch_member(postgresql.name, postgresql.connection_string)
         etcd_ready = True
     except urllib2.URLError:
-        print "waiting on etcd"
+        logging.info("waiting on etcd")
         time.sleep(5)
 
 # is data directory empty?
@@ -54,7 +59,7 @@ else:
     postgresql.start()
 
 while True:
-    print ha.run_cycle()
+    logging.info(ha.run_cycle())
 
     # create replication slots
     if postgresql.is_leader():

helpers/etcd.py

@@ -1,7 +1,10 @@
 import urllib2, json, os, time
+import logging
 from urllib import urlencode
 import helpers.errors
 
+logger = logging.getLogger(__name__)
+
 class Etcd:
     def __init__(self, config):
         self.scope = config["scope"]
@@ -19,7 +22,7 @@ class Etcd:
             except (urllib2.HTTPError, urllib2.URLError) as e:
                 attempts += 1
                 if attempts < max_attempts:
-                    print "Failed to return %s, trying again. (%s of %s)" % (path, attempts, max_attempts)
+                    logger.info("Failed to return %s, trying again. (%s of %s)" % (path, attempts, max_attempts))
                     time.sleep(3)
                 else:
                     raise e
@@ -73,14 +76,14 @@ class Etcd:
             return self.put_client_path("/leader", {"value": value, "ttl": self.ttl, "prevExist": False}) == None
         except urllib2.HTTPError as e:
             if e.code == 412:
-                print("Could not take out TTL lock: %s" % e)
+                logger.info("Could not take out TTL lock: %s" % e)
             return False
 
     def update_leader(self, value):
         try:
             self.put_client_path("/leader", {"value": value, "ttl": self.ttl, "prevValue": value})
         except urllib2.HTTPError:
-            print "Error updating TTL on ETCD for primary."
+            logger.error("Error updating TTL on ETCD for primary.")
             return False
 
     def leader_unlocked(self):
@@ -97,7 +100,7 @@ class Etcd:
     def am_i_leader(self, value):
         #try:
            reponse = self.get_client_path("/leader")
-           print "Lock owner: %s; I am %s" % (reponse["node"]["value"], value)
+           logger.info("Lock owner: %s; I am %s" % (reponse["node"]["value"], value))
            return reponse["node"]["value"] == value
         #except Exception as e:
             #return False

helpers/ha.py

@@ -1,10 +1,14 @@
 import sys, time, re, urllib2, json, psycopg2
+import logging
 from base64 import b64decode
 
 import helpers.errors
 
 import inspect
 
+logger = logging.getLogger(__name__)
+
+
 def lineno():
     """Returns the current line number in our program."""
     return inspect.currentframe().f_back.f_lineno
@@ -65,7 +69,7 @@ class Ha:
                         else:
                             return "no action.  i am the leader with the lock"
                     else:
-                        print "does not have lock"
+                        logger.info("does not have lock")
                         if self.state_handler.is_leader():
                             self.state_handler.demote(self.fetch_current_leader())
                             return "demoting self because i do not have the lock and i was a leader"
@@ -78,11 +82,11 @@ class Ha:
                     return "postgresql was stopped.  starting again."
                 return "no action.  not healthy enough to do anything."
         except helpers.errors.CurrentLeaderError:
-            print "failed to fetch current leader from etcd"
+            logger.error("failed to fetch current leader from etcd")
         except psycopg2.OperationalError:
-            print "Error communicating with Postgresql.  Will try again."
+            logger.error("Error communicating with Postgresql.  Will try again.")
         except helpers.errors.HealthiestMemberError:
-            print "failed to determine healthiest member fromt etcd"
+            logger.error("failed to determine healthiest member fromt etcd")
 
     def run(self):
         while True:

helpers/postgresql.py

@@ -1,6 +1,12 @@
 import os, psycopg2, re, time
+import logging
+
 from urlparse import urlparse
 
+
+logger = logging.getLogger(__name__)
+
+
 class Postgresql:
 
     def __init__(self, config):
@@ -28,7 +34,7 @@ class Postgresql:
         try:
             self.conn.close()
         except Exception as e:
-            print "Error disconnecting: %s" % e
+            logger.error("Error disconnecting: %s" % e)
 
     def query(self, sql):
         max_attempts = 0
@@ -78,13 +84,13 @@ class Postgresql:
 
     def start(self):
         if self.is_running():
-            print "Cannot start PostgreSQL because one is already running."
+            logger.error("Cannot start PostgreSQL because one is already running.")
             return False
 
         pid_path = "%s/postmaster.pid" % self.data_dir
         if os.path.exists(pid_path):
             os.remove(pid_path)
-            print "Removed %s" % pid_path
+            logger.info("Removed %s" % pid_path)
 
         command_code = os.system("postgres -D %s %s &" % (self.data_dir, self.server_options()))
         time.sleep(5)
@@ -107,7 +113,7 @@ class Postgresql:
 
     def is_healthy(self):
         if not self.is_running():
-            print "Postgresql is not running."
+            logger.warning("Postgresql is not running.")
             return False
 
         return True
@@ -122,7 +128,7 @@ class Postgresql:
                 member_cursor = member_conn.cursor()
                 member_cursor.execute("SELECT '%s'::pg_lsn - pg_last_xlog_replay_location() AS bytes;" % self.xlog_position())
                 xlog_diff = member_cursor.fetchone()[0]
-                print [self.name, member["hostname"], xlog_diff]
+                logger.info([self.name, member["hostname"], xlog_diff])
                 if xlog_diff < 0:
                     member_cursor.close()
                     return False