Merge branch 'logging' into 'master'

Use logging module in ci-bootstrap.py

Closes #34

See merge request openappstack/bootstrap!19

.gitignore

@@ -7,3 +7,4 @@
 /test/env/extravars
 
 __pycache__
+*.log

test/ci-bootstrap.py

 #!/usr/bin/env python3
-"""
+r"""
 Used by CI to bootstrap a new cluster and run tests.
 
 Prerequisites
@@ -8,18 +8,22 @@ Prerequisites
   - ansible-runner
   - requests
   - tabulate
+  - psutil
 
 Env vars needed:
 - COSMOS_API_TOKEN
 
 In Debian:
-    apt-get install -y --no-install-recommends ansible gcc libc6-dev
+    apt-get install -y --no-install-recommends ansible gcc libc6-dev \
+      python3-distutils python3-pip python3-setuptools python3-wheel \
+      python3-psutil
     pip3 install ansible-runner requests tabulate
 """
 
 import ansible_runner
 import argparse
 import cosmos
+import logging
 import os
 import random
 import string
@@ -28,8 +32,28 @@ import traceback
 import yaml
 
 
+def init_logging(log, loglevel):
+    """
+    Configure logging.
+
+    - debug and info go to stdout
+    - warning and above go to stderr
+    """
+    log.setLevel(loglevel)
+    stdout = logging.StreamHandler(sys.stdout)
+    stdout.setLevel(loglevel)
+    stdout.addFilter(lambda record: record.levelno <= logging.INFO)
+
+    stderr = logging.StreamHandler()
+    stderr.setLevel(logging.WARNING)
+
+    log.addHandler(stdout)
+    log.addHandler(stderr)
+
+
 if __name__ == "__main__":
 
+    # Parse command line arguments
     parser = argparse.ArgumentParser(
         description='Run bootstrap script'
         'to deploy Openappstack to a given node.')
@@ -64,7 +88,17 @@ if __name__ == "__main__":
 
     args = parser.parse_args()
     verbose = args.verbose
+    loglevel = logging.DEBUG if verbose else logging.INFO
+
+    # Setup logging for this script
+    log = logging.getLogger(__name__)
+    init_logging(log, loglevel)
+
+    # Setup logging for cosmos module
+    log_cosmos = logging.getLogger('cosmos')
+    init_logging(log_cosmos, loglevel)
 
+    # Start bootstrapping
     if args.create_droplet:
         # Create droplet
 
@@ -90,7 +124,7 @@ if __name__ == "__main__":
             disk=8,
             image=18)
         id = droplet['droplet']['id']
-        print('Created droplet id:', id)
+        log.info('Created droplet id: %s', id)
         cosmos.wait_for_state(id, 'running')
     else:
         id = args.droplet_id
@@ -104,14 +138,15 @@ if __name__ == "__main__":
     name = droplet['name']
 
     # Create domain records
-    new_record = cosmos.create_domain_record(
-        domain='openappstack.net', name=name + '.ci', data=ip, record_type='A')
-    print(new_record)
+    domain_record = cosmos.create_domain_record(
+        domain='openappstack.net', name=name + '.ci', data=ip, record_type='A',
+        update=True)
+    log.info("Domain record: %s", domain_record)
 
-    new_record = cosmos.create_domain_record(
+    domain_record = cosmos.create_domain_record(
         domain='openappstack.net', name='*.' + name + '.ci', data=name + '.ci',
-        record_type='CNAME')
-    print(new_record)
+        record_type='CNAME', update=True)
+    log.info("Domain record: %s", domain_record)
 
     if verbose:
         cosmos.list_domain_records('openappstack.net')
@@ -147,9 +182,8 @@ if __name__ == "__main__":
     with open('./env/extravars', 'w') as stream:
         yaml.dump(settings, stream, default_flow_style=False)
 
-    if verbose:
-        print(yaml.dump(inventory, default_flow_style=False))
-        print(yaml.dump(settings, default_flow_style=False))
+    log.debug(yaml.dump(inventory, default_flow_style=False))
+    log.debug(yaml.dump(settings, default_flow_style=False))
 
     # Bootstrap
     # playbook path here is relative to private_data_dir/project, see
@@ -157,13 +191,12 @@ if __name__ == "__main__":
     ansible_run = ansible_runner.run(
         private_data_dir='.',
         playbook='../../ansible/bootstrap.yml')
-    print('ansible_run.rc:', ansible_run.rc)
-    print('ansible_run.status:', ansible_run.status, '\n')
+    log.info('ansible_run.rc: %s', ansible_run.rc)
+    log.info('ansible_run.status: %s\n', ansible_run.status)
 
-    if verbose:
-        print('ansible_run.stats:', ansible_run.stats)
-        for each_host_event in ansible_run.events:
-            print('ansible_run.events.each_host_event["event"]',
+    log.debug('ansible_run.stats: %s', ansible_run.stats)
+    for each_host_event in ansible_run.events:
+        log.debug('ansible_run.events.each_host_event["event"]: %s',
                   each_host_event['event'])
 
     if ansible_run.rc > 0:

test/cosmos.py

@@ -2,6 +2,7 @@
 """Python module with helper functions to use the cosmos API."""
 
 import json
+import logging
 import os
 import re
 import requests
@@ -12,15 +13,14 @@ from time import sleep
 
 
 # Helper functions
-
 def request_api(resource: str, request_type: str = 'GET',
-                data: str = '', verbose: bool = False):
+                data: str = ''):
     """Query the cosmos API."""
     if 'COSMOS_API_TOKEN' in os.environ:
         api_token = os.environ['COSMOS_API_TOKEN']
     else:
-        print('Please export the COSMOS_API_TOKEN environment variable.')
-        sys.exit(1)
+        raise ValueError('Please export the COSMOS_API_TOKEN'
+                         'environment variable.')
 
     headers = {'Content-Type': 'application/json',
                'Authorization': 'Bearer {0}'.format(api_token)}
@@ -34,18 +34,20 @@ def request_api(resource: str, request_type: str = 'GET',
     elif request_type == 'POST':
         response = requests.post(
             api_url, headers=headers, data=json.dumps(data))
+    elif request_type == 'PUT':
+        response = requests.put(
+            api_url, headers=headers, data=json.dumps(data))
     else:
-        raise ValueError('Specify one of GET/DELETE/POST as request_type.')
+        raise ValueError('Specify one of GET/DELETE/POST/PUT as request_type.')
 
-    if verbose:
-        print('Request: ', response.url, ', ', request_type, ', data: ', data)
-        print('Response code ', response.status_code)
+    log.debug('Request: %s, %s, data: %s',
+              response.url, request_type, data)
+    log.debug('Response code: %s', response.status_code)
 
     status_code_ok = [200, 201, 202, 204]
     if response.status_code in status_code_ok:
         if response.content:
-            if verbose:
-                print('Response: ', response.json(), '\n')
+            log.debug('Response: %s\n', response.json())
             return json.loads(response.content.decode('utf-8'))
         else:
             return None
@@ -56,15 +58,35 @@ def request_api(resource: str, request_type: str = 'GET',
 
 # API calls
 def create_domain_record(domain: str, name: str, data: str,
-                         record_type: str = 'A'):
-    """Create domain record."""
-    print('Creating domain record')
+                         record_type: str = 'A', update: bool = False):
+    """Create domain record.
+
+    If 'update' is set to True, the record will be updated if it exists.
+    """
+    log.info('Creating domain record')
+
     record = {
         'name': name,
         'data': data,
         'type': record_type
     }
-    response = request_api('domains/' + domain + '/records/', 'POST', record)
+    # Check if record exists
+    existing_record = get_domain_record_by_name(domain=domain, name=name,
+                                                record_type=record_type)
+    if existing_record:
+        if update:
+            log.info('Domain record exists - Updating the record.')
+            response = request_api(
+                'domains/%s/records/%s' % (domain, existing_record['id']),
+                'PUT', record)
+        else:
+            raise ValueError('Domain record exists - Doing nothing,'
+                             'please use "update=True" to update existing'
+                             'records.')
+    else:
+        log.info('Creating new record.')
+        response = request_api('domains/%s/records/' % domain, 'POST', record)
+
     return response['domain_record']
 
 
@@ -82,7 +104,7 @@ def create_droplet(name: str, ssh_key_id: int, region: str = 'ams1',
       - size (int): 2048 (2GB RAM)
       - disk (int): 20 (20GB disk space)
     """
-    print('Creating droplet')
+    log.info('Creating droplet')
 
     data = {
         "name": name,
@@ -98,7 +120,7 @@ def create_droplet(name: str, ssh_key_id: int, region: str = 'ams1',
 
 def delete_droplet(id: int):
     """Delete a droplet. Droplet needs to be stopped first."""
-    print('Deleting', id)
+    log.info('Deleting %s', id)
     response = request_api('droplets/{0}'.format(id), 'DELETE')
     return response
 
@@ -109,6 +131,26 @@ def get_domain_record(domain: str, id: int):
     return response['domain_record']
 
 
+def get_domain_record_by_name(domain: str, name: str,
+                              record_type: str = 'A'):
+    """
+    Get domain record for given name and type.
+
+    Example:
+    get_domain_record_by_name(domain='openappstack.net', name='varac-oas')
+    """
+    records = get_domain_records(domain=domain)
+    matching = None
+    for record in records:
+        if record['name'] == name and record['type'] == record_type:
+            matching = record
+            break
+    if not matching:
+        log.info('No domain record found.')
+
+    return matching
+
+
 def get_domain_records(domain: str):
     """Get domain records for given domain."""
     response = request_api('domains/{0}/records'.format(domain))
@@ -127,7 +169,6 @@ def get_droplets_by_name(name_regex: str):
 
     Example:
         get_droplets_by_name(name_regex='^ci\d+')
-      will match i.e. 'ci1234', 'ci1', etc
     """
     all_droplets = get_droplets()
     matching = [droplet for droplet in all_droplets
@@ -141,25 +182,24 @@ def get_droplet(id: int):
     return response['droplet']
 
 
-def list_domain_records(domain: str, verbose: bool = False):
+def list_domain_records(domain: str):
     """List domain records for given domain."""
     records = get_domain_records(domain)
 
-    if verbose:
-        print(json.dumps(records, sort_keys=True, indent=2))
+    log.debug(json.dumps(records, sort_keys=True, indent=2))
 
     table_records = [[
         record['id'], record['name'], record['type'], record['data']]
         for record in records]
-    print(tabulate(table_records, headers=['ID', 'Name', 'Type', 'Data']))
+    log.info(tabulate(table_records,
+             headers=['ID', 'Name', 'Type', 'Data']))
 
 
-def list_droplets(verbose: bool = False):
+def list_droplets():
     """List all droplets by their ID, Name, IP and state."""
     droplets = get_droplets()
 
-    if verbose:
-        print(json.dumps(droplets, sort_keys=True, indent=2))
+    log.debug(json.dumps(droplets, sort_keys=True, indent=2))
 
     table_droplets = [[
         droplet['id'],
@@ -168,12 +208,13 @@ def list_droplets(verbose: bool = False):
         droplet['status']]
         for droplet in droplets]
 
-    print(tabulate(table_droplets, headers=['ID', 'Name', 'IPv4', 'Status']))
+    log.info(tabulate(table_droplets,
+                      headers=['ID', 'Name', 'IPv4', 'Status']))
 
 
 def shutdown_droplet(id: int):
     """Shut down specified droplet (through a power_off call)."""
-    print('Shutting down', id)
+    log.info('Shutting down %s', id)
     data = {"type": "power_off"}
     response = request_api('droplets/{0}/actions'.format(id), 'POST', data)
     return response
@@ -208,7 +249,7 @@ def terminate_droplets_by_name(name_regex: str):
 
 def wait_for_ssh(ip: str):
     """Wait for ssh to be reachable on port 22."""
-    print('Waiting for ssh to become available on ip', ip, '...')
+    log.info('Waiting for ssh to become available on ip %s', ip)
 
     sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
 
@@ -216,11 +257,23 @@ def wait_for_ssh(ip: str):
         sleep(1)
 
 
-def wait_for_state(id: int, state, verbose=False):
+def wait_for_state(id: int, state):
     """Wait for a droplet to reach a certain state."""
-    print('Waiting for droplet', id, 'to reach', state, 'state...')
-    if verbose:
-        print(status_droplet(id))
+    log.info('Waiting for droplet %s to reach %s state...', id, state)
+    status = status_droplet(id)
+    log.debug(status)
 
-    while status_droplet(id) != state:
+    while status != state:
         sleep(1)
+        status = status_droplet(id)
+
+
+# When called from from ipython, setup
+# logging to console
+try:
+    __IPYTHON__
+    log = logging.getLogger()
+    log.addHandler(logging.StreamHandler())
+    log.setLevel(logging.INFO)
+except NameError:
+    log = logging.getLogger(__name__)