Try to add logging

1 files changed, 69 insertions, 53 deletions

diff --git a/GitAutoDeploy.py b/GitAutoDeploy.py
index a444b7f..0786a89 100755
--- a/GitAutoDeploy.py
+++ b/GitAutoDeploy.py
@@ -1,5 +1,9 @@
 #!/usr/bin/env python
 
+import logging
+# Initialize loging
+logFormatter = logging.Formatter("%(asctime)s [%(threadName)-12.12s] [%(levelname)-5.5s]  %(message)s")
+logger = logging.getLogger()
 
 class Lock():
     """Simple implementation of a mutex lock using the file systems. Works on *nix systems."""
@@ -16,7 +20,7 @@ class Lock():
         try:
             os.open(self.path, os.O_CREAT | os.O_EXCL | os.O_WRONLY)
             self._has_lock = True
-            print "Successfully obtained lock: %s" % self.path
+            logger.info("Successfully obtained lock: %s" % self.path)
         except OSError:
             return False
         else:
@@ -29,7 +33,7 @@ class Lock():
             raise Exception("Unable to release lock that is owned by another process")
         try:
             os.remove(self.path)
-            print "Successfully released lock: %s" % self.path
+            logger.info("Successfully released lock: %s" % self.path)
         finally:
             self._has_lock = False
 
@@ -44,7 +48,7 @@ class Lock():
         except OSError:
             pass
         finally:
-            print "Successfully cleared lock: %s" % self.path
+            logger.info("Successfully cleared lock: %s" % self.path)
             self._has_lock = False
 
 
@@ -62,10 +66,10 @@ class GitWrapper():
         branch = ('branch' in repo_config) and repo_config['branch'] or 'master'
         remote = ('remote' in repo_config) and repo_config['remote'] or 'origin'
 
-        print "Post push request received"
+        logger.info("Post push request received")
 
         if 'path' in repo_config:
-            print 'Updating ' + repo_config['path']
+            logger.info('Updating ' + repo_config['path'])
 
             cmd = 'cd "' + repo_config['path'] + '"' \
                   '&& unset GIT_DIR ' + \
@@ -77,7 +81,7 @@ class GitWrapper():
             # '&& git update-index --refresh ' +\
 
             res = call([cmd], shell=True)
-            print 'Pull result: ' + str(res)
+            logger.info('Pull result: ' + str(res))
 
             return int(res)
 
@@ -112,7 +116,7 @@ class GitWrapper():
         if len(gd[1]) is not 0:
             cmds.append(gd[1])
 
-        print 'Executing deploy command(s)'
+        logger.info('Executing deploy command(s)')
 
         for cmd in cmds:
             if 'path' in repo_config:
@@ -165,10 +169,10 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
         # Assume GitLab if the X-Gitlab-Event HTTP header is set
         if gitlab_event:
 
-            print "Received '%s' event from GitLab" % gitlab_event
+            logger.info("Received '%s' event from GitLab" % gitlab_event)
 
             if not 'repository' in data:
-                print "ERROR - Unable to recognize data format"
+                logger.error("ERROR - Unable to recognize data format")
                 return repo_urls, ref or "master", action
 
             # One repository may posses multiple URLs for different protocols
@@ -179,10 +183,10 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
         # Assume GitHub if the X-GitHub-Event HTTP header is set
         elif github_event:
 
-            print "Received '%s' event from GitHub" % github_event
+            logger.info("Received '%s' event from GitHub" % github_event)
 
             if not 'repository' in data:
-                print "ERROR - Unable to recognize data format"
+                logger.error("ERROR - Unable to recognize data format")
                 return repo_urls, ref or "master", action
 
             # One repository may posses multiple URLs for different protocols
@@ -194,22 +198,22 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
                 if 'base' in data['pull_request']:
                     if 'ref' in data['pull_request']['base']:
                         ref = data['pull_request']['base']['ref']
-                        print "Pull request to branch '%s' was fired" % ref
+                        logger.info("Pull request to branch '%s' was fired" % ref)
             elif 'ref' in data:
                 ref = data['ref']
-                print "Push to branch '%s' was fired" % ref
+                logger.info("Push to branch '%s' was fired" % ref)
 
             if 'action' in data:
                 action = data['action']
-                print "Action '%s' was fired" % action
+                logger.info("Action '%s' was fired" % action)
 
         # Assume BitBucket if the User-Agent HTTP header is set to 'Bitbucket-Webhooks/2.0' (or something similar)
         elif user_agent and user_agent.lower().find('bitbucket') != -1:
 
-            print "Received event from BitBucket"
+            logger.info("Received event from BitBucket")
 
             if not 'repository' in data:
-                print "ERROR - Unable to recognize data format"
+                logger.error("ERROR - Unable to recognize data format")
                 return repo_urls, ref or "master", action
 
             # One repository may posses multiple URLs for different protocols
@@ -227,10 +231,10 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
         # Special Case for Gitlab CI
         elif content_type == "application/json" and "build_status" in data:
 
-            print 'Received event from Gitlab CI'
+            logger.info('Received event from Gitlab CI')
 
             if not 'push_data' in data:
-                print "ERROR - Unable to recognize data format"
+                logger.error("ERROR - Unable to recognize data format")
                 return repo_urls, ref or "master", action
 
             # Only add repositories if the build is successful. Ignore it in other case.
@@ -239,17 +243,17 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
                     if k in data['push_data']['repository']:
                         repo_urls.append(data['push_data']['repository'][k])
             else:
-                print "Gitlab CI build '%d' has status '%s'. Not pull will be done" % (
-                data['build_id'], data['build_status'])
+                logger.warning("Gitlab CI build '%d' has status '%s'. Not pull will be done" % (
+                data['build_id'], data['build_status']))
 
         # Try to find the repository urls and add them as long as the content type is set to JSON at least.
         # This handles old GitLab requests and Gogs requests for example.
         elif content_type == "application/json":
 
-            print "Received event from unknown origin. Assume generic data format."
+            logger.info("Received event from unknown origin. Assume generic data format.")
 
             if not 'repository' in data:
-                print "ERROR - Unable to recognize data format"
+                logger.error("ERROR - Unable to recognize data format")
                 return repo_urls, ref or "master", action
 
             # One repository may posses multiple URLs for different protocols
@@ -257,7 +261,7 @@ class WebhookRequestHandler(BaseHTTPRequestHandler):
                 if k in data['repository']:
                     repo_urls.append(data['repository'][k])
         else:
-            print "ERROR - Unable to recognize request origin. Don't know how to handle the request."
+            logger.error("ERROR - Unable to recognize request origin. Don't know how to handle the request.")
 
         return repo_urls, ref or "master", action
 
@@ -285,13 +289,13 @@ class GitAutoDeploy(object):
 
         pid = GitAutoDeploy.get_pid_on_port(port)
         if pid is False:
-            print 'I don\'t know the number of pid that is using my configured port'
+            logger.warning('I don\'t know the number of pid that is using my configured port')
             return
 
-        print 'Process with pid number %s is using port %s' % (pid, port)
+        logger.info('Process with pid number %s is using port %s' % (pid, port))
         with open("/proc/%s/cmdline" % pid) as f:
             cmdline = f.readlines()
-            print 'cmdline ->', cmdline[0].replace('\x00', ' ')
+            logger.info('cmdline ->', cmdline[0].replace('\x00', ' '))
 
     @staticmethod
     def get_pid_on_port(port):
@@ -341,7 +345,7 @@ class GitAutoDeploy(object):
         repo_configs = GitAutoDeploy().get_matching_repo_configs(urls)
 
         if len(repo_configs) == 0:
-            print 'Unable to find any of the repository URLs in the config: %s' % ', '.join(urls)
+            logger.warning('Unable to find any of the repository URLs in the config: %s' % ', '.join(urls))
             return
 
         # Process each matching repository
@@ -361,8 +365,8 @@ class GitAutoDeploy(object):
 
                         # If we're unable, try once to obtain the status_waiting lock
                         if not waiting_lock.has_lock() and not waiting_lock.obtain():
-                            print "Unable to obtain the status_running lock nor the status_waiting lock. Another process is " \
-                                  + "already waiting, so we'll ignore the request."
+                            logger.error("Unable to obtain the status_running lock nor the status_waiting lock. Another process is " \
+                                  + "already waiting, so we'll ignore the request.")
 
                             # If we're unable to obtain the waiting lock, ignore the request
                             break
@@ -379,8 +383,8 @@ class GitAutoDeploy(object):
 
             except Exception as e:
                 if 'path' in repo_config:
-                    print 'Error during \'pull\' or \'deploy\' operation on path: %s' % repo_config['path']
-                print e
+                    logger.error('Error during \'pull\' or \'deploy\' operation on path: %s' % repo_config['path'])
+                logger.error(e)
 
             finally:
 
@@ -416,7 +420,7 @@ class GitAutoDeploy(object):
             for item in os.listdir(dir):
                 if re.match(r"conf(ig)?\.json$", item):
                     path = os.path.realpath(os.path.join(dir, item))
-                    print "Using '%s' as config" % path
+                    logger.info("Using '%s' as config" % path)
                     return path
 
         return './GitAutoDeploy.conf.json'
@@ -437,14 +441,14 @@ class GitAutoDeploy(object):
             config_string = open(self.config_path).read()
 
         except Exception as e:
-            print "Could not load %s file\n" % self.config_path
+            logger.warning("Could not load %s file\n" % self.config_path)
             raise e
 
         try:
             self._config = json.loads(config_string)
 
         except Exception as e:
-            print "%s file is not valid JSON\n" % self.config_path
+            logger.error("%s file is not valid JSON\n" % self.config_path)
             raise e
 
         # Translate any ~ in the path into /home/<user>
@@ -469,20 +473,20 @@ class GitAutoDeploy(object):
             if 'path' in repo_config:
                 if not os.path.isdir(repo_config['path']):
 
-                    print "Directory %s not found" % repo_config['path']
+                    logger.error("Directory %s not found" % repo_config['path'])
                     GitWrapper.clone(url=repo_config['url'], branch=repo_config['branch'] if 'branch' in repo_config else None, path=repo_config['path'])
 
                     if not os.path.isdir(repo_config['path']):
-                        print "Unable to clone %s branch of repository %s. So repo will not pull. Only deploy command will run(if it exist)" % (repo_config['branch'] if 'branch' in repo_config else "default", repo_config['url'])
+                        logger.warning("Unable to clone %s branch of repository %s. So repo will not pull. Only deploy command will run(if it exist)" % (repo_config['branch'] if 'branch' in repo_config else "default", repo_config['url']))
                         #sys.exit(2)
 
                     else:
-                        print "Repository %s successfully cloned" % repo_config['url']
+                        logger.info("Repository %s successfully cloned" % repo_config['url'])
                 if not os.path.isdir(repo_config['path'] + '/.git'):
-                    print "Directory %s is not a Git repository. So repo will not pull. Only deploy command will run(if it exist)" % repo_config['path']
+                    logger.warning("Directory %s is not a Git repository. So repo will not pull. Only deploy command will run(if it exist)" % repo_config['path'])
                     #sys.exit(2)
             else:
-                print "'Path' was not found in config. So repo will not pull. Only deploy command will run(if it exist)"
+                logger.warning("'Path' was not found in config. So repo will not pull. Only deploy command will run(if it exist)")
 
         return self._config
 
@@ -510,7 +514,7 @@ class GitAutoDeploy(object):
         for repository in self.get_config()['repositories']:
 
             url = repository['url']
-            print "Scanning repository: %s" % url
+            logger.info("Scanning repository: %s" % url)
             m = re.match('.*@(.*?):', url)
 
             if m is not None:
@@ -519,7 +523,7 @@ class GitAutoDeploy(object):
                 call(['ssh-keyscan -t ecdsa,rsa ' + port + ' ' + m.group(1) + ' >> $HOME/.ssh/known_hosts'], shell=True)
 
             else:
-                print 'Could not find regexp match in path: %s' % url
+                logger.error('Could not find regexp match in path: %s' % url)
 
     def kill_conflicting_processes(self):
         import os
@@ -527,8 +531,8 @@ class GitAutoDeploy(object):
         pid = GitAutoDeploy.get_pid_on_port(self.get_config()['port'])
 
         if pid is False:
-            print '[KILLER MODE] I don\'t know the number of pid that is using my configured port\n ' \
-                  '[KILLER MODE] Maybe no one? Please, use --force option carefully'
+            logger.error('[KILLER MODE] I don\'t know the number of pid that is using my configured port\n ' \
+                  '[KILLER MODE] Maybe no one? Please, use --force option carefully')
             return False
 
         os.kill(pid, signal.SIGKILL)
@@ -552,7 +556,7 @@ class GitAutoDeploy(object):
     def exit(self):
         import sys
 
-        print '\nGoodbye'
+        logger.info('\nGoodbye')
         self.remove_pid_file()
         sys.exit(0)
 
@@ -618,27 +622,39 @@ class GitAutoDeploy(object):
             self.daemon = True
 
         if '--ssh-keygen' in argv:
-            print 'Scanning repository hosts for ssh keys...'
+            logger.info('Scanning repository hosts for ssh keys...')
             self.ssh_key_scan()
 
         if '--force' in argv:
-            print 'Attempting to kill any other process currently occupying port %s' % self.get_config()['port']
+            logger.info('Attempting to kill any other process currently occupying port %s' % self.get_config()['port'])
             self.kill_conflicting_processes()
 
         if '--config' in argv:
             pos = argv.index('--config')
             if len(argv) > pos + 1:
                 self.config_path = os.path.realpath(argv[argv.index('--config') + 1])
-                print 'Using custom configuration file \'%s\'' % self.config_path
+                logger.info('Using custom configuration file \'%s\'' % self.config_path)
 
         # Initialize config
         self.get_config()
 
+        # All logs are recording
+        logger.setLevel(logging.NOTSET)
+
+        # Translate any ~ in the path into /home/<user>
+        fileHandler = logging.FileHandler(os.path.expanduser(self.get_config()["logfilepath"]))
+        fileHandler.setFormatter(logFormatter)
+        logger.addHandler(fileHandler)
+
+        consoleHandler = logging.StreamHandler()
+        consoleHandler.setFormatter(logFormatter)
+        logger.addHandler(consoleHandler)
+
         if self.daemon:
-            print 'Starting Git Auto Deploy in daemon mode'
+            logger.info('Starting Git Auto Deploy in daemon mode')
             GitAutoDeploy.create_daemon()
         else:
-            print 'Git Auto Deploy started'
+            logger.info('Git Auto Deploy started')
 
         self.create_pid_file()
 
@@ -655,13 +671,13 @@ class GitAutoDeploy(object):
         try:
             self._server = HTTPServer((self.get_config()['host'], self.get_config()['port']), WebhookRequestHandler)
             sa = self._server.socket.getsockname()
-            print "Listening on", sa[0], "port", sa[1]
+            logger.info("Listening on", sa[0], "port", sa[1])
             self._server.serve_forever()
 
         except socket.error, e:
 
             if not GitAutoDeploy.daemon:
-                print "Error on socket: %s" % e
+                logger.critical("Error on socket: %s" % e)
                 GitAutoDeploy.debug_diagnosis(self.get_config()['port'])
 
             sys.exit(1)
@@ -678,10 +694,10 @@ class GitAutoDeploy(object):
             return
 
         elif signum == 2:
-            print '\nRequested close by keyboard interrupt signal'
+            logger.info('\nRequested close by keyboard interrupt signal')
 
         elif signum == 6:
-            print 'Requested close by SIGABRT (process abort signal). Code 6.'
+            logger.info('Requested close by SIGABRT (process abort signal). Code 6.')
 
         self.exit()