enable timerotateloghandler (configurable)

caravel/__init__.py

@@ -4,7 +4,7 @@
 from __future__ import print_function
 from __future__ import unicode_literals
 
-import logging
+import logging.config
 import os
 
 from flask import Flask, redirect
@@ -16,10 +16,6 @@
 APP_DIR = os.path.dirname(__file__)
 CONFIG_MODULE = os.environ.get('CARAVEL_CONFIG', 'caravel.config')
 
-# Logging configuration
-logging.basicConfig(format='%(asctime)s:%(levelname)s:%(name)s:%(message)s')
-logging.getLogger().setLevel(logging.DEBUG)
-
 app = Flask(__name__)
 app.config.from_object(CONFIG_MODULE)
 db = SQLA(app)
@@ -28,6 +24,10 @@
 
 migrate = Migrate(app, db, directory=APP_DIR + "/migrations")
 
+# Logging configuration
+logging.config.dictConfig(app.config.get('LOGGING_CONFIG'))
+logger = logging.getLogger(__name__)
+
 
 class MyIndexView(IndexView):
     @expose('/')

caravel/bin/caravel

@@ -17,6 +17,7 @@ from caravel import data, utils
 from caravel import db
 
 config = app.config
+logger = logging.getLogger(__name__)
 
 manager = Manager(app)
 manager.add_command('db', MigrateCommand)
@@ -36,8 +37,9 @@ manager.add_command('db', MigrateCommand)
     help="Specify the timeout (seconds) for the gunicorn web server")
 def runserver(debug, port, timeout, workers):
     """Starts a Caravel web server"""
-    debug = debug or config.get("DEBUG")
-    if debug:
+    debug = config.get('LOG_LEVEL')
+
+    if debug == 'DEBUG':
         app.run(
             host='0.0.0.0',
             port=int(port),
@@ -49,7 +51,7 @@ def runserver(debug, port, timeout, workers):
             "--timeout {timeout} "
             "-b 0.0.0.0:{port} "
             "caravel:app").format(**locals())
-        print("Starting server with command: " + cmd)
+        logger.info("Starting server with command: " + cmd)
         Popen(cmd, shell=True).wait()
 
 @manager.command
@@ -62,17 +64,17 @@ def init():
     help="Only load 1000 rows (faster, used for testing)")
 def load_examples(sample):
     """Loads a set of Slices and Dashboards and a supporting dataset """
-    print("Loading examples into {}".format(db))
+    logger.info("Loading examples into {}".format(db))
 
     data.load_css_templates()
 
-    print("Loading energy related dataset")
+    logger.info("Loading energy related dataset")
     data.load_energy()
 
-    print("Loading [World Bank's Health Nutrition and Population Stats]")
+    logger.info("Loading [World Bank's Health Nutrition and Population Stats]")
     data.load_world_bank_health_n_pop()
 
-    print("Loading [Birth names]")
+    logger.info("Loading [Birth names]")
     data.load_birth_names()
 
 @manager.command
@@ -84,12 +86,12 @@ def refresh_druid():
         try:
             cluster.refresh_datasources()
         except Exception as e:
-            print(
+            logger.info(
                 "Error while processing cluster '{}'\n{}".format(
                     cluster, str(e)))
-            logging.exception(e)
+            logger.exception(e)
         cluster.metadata_last_refreshed = datetime.now()
-        print(
+        logger.info(
             "Refreshed metadata from cluster "
             "[" + cluster.cluster_name + "]")
     session.commit()

caravel/config.py

@@ -40,9 +40,6 @@
 # Flask-WTF flag for CSRF
 CSRF_ENABLED = True
 
-# Whether to run the web server in debug mode or not
-DEBUG = False
-
 # Whether to show the stacktrace on 500 error
 SHOW_STACKTRACE = True
 
@@ -121,6 +118,57 @@
 CACHE_DEFAULT_TIMEOUT = None
 CACHE_CONFIG = {'CACHE_TYPE': 'null'}
 
+"""
+Settings for root logger.
+1) Log messages will be printed to console a
+2) also to log file (rotated, with specified size).
+
+Reference:
+1) http://docs.python-guide.org/en/latest/writing/logging/
+2) https://docs.python.org/2/library/logging.config.html
+"""
+
+# ---------------------------------------------------
+# Logging Configuration
+# ---------------------------------------------------
+# LOG_LEVEL = DEBUG, INFO, WARNING, ERROR, CRITICAL
+
+LOG_LEVEL = 'DEBUG'
+LOG_LOCATION = '/tmp/caravel.log'
+
+LOGGING_CONFIG = {
+    'version': 1,
+    'disable_existing_loggers': False,
+    'formatters': {
+        'standard': {
+            'format': '(%(asctime)s; %(filename)s:%(lineno)d) : %(levelname)s:%(name)s: %(message)s ',
+            'datefmt': "%Y-%m-%d %H:%M:%S",
+        }
+    },
+    'handlers': {
+        'console': {
+            'level': LOG_LEVEL,
+            'formatter': 'standard',
+            'class': 'logging.StreamHandler',
+        },
+        'rotate_file': {
+            'level': LOG_LEVEL,
+            'formatter': 'standard',
+            'class': 'logging.handlers.RotatingFileHandler',
+            'filename': LOG_LOCATION,
+            'encoding': 'utf8',
+            'maxBytes': 10000000,
+            'backupCount': 1,
+        }
+    },
+    'loggers': {
+        '': {
+            'handlers': ['console', 'rotate_file'],
+            'level': LOG_LEVEL,
+        },
+    }
+}
+
 try:
     from caravel_config import *  # noqa
 except Exception:

caravel/data/__init__.py

@@ -6,6 +6,7 @@
 
 import gzip
 import json
+import logging
 import os
 import textwrap
 
@@ -21,16 +22,17 @@
 Dash = models.Dashboard
 
 config = app.config
+logger = logging.getLogger(__name__)
 
 DATA_FOLDER = os.path.join(config.get("BASE_DIR"), 'data')
 
 
 def get_or_create_db(session):
-    print("Creating database reference")
+    logger.info("Creating database reference")
     dbobj = session.query(DB).filter_by(database_name='main').first()
     if not dbobj:
         dbobj = DB(database_name="main")
-    print(config.get("SQLALCHEMY_DATABASE_URI"))
+    logger.info(config.get("SQLALCHEMY_DATABASE_URI"))
     dbobj.sqlalchemy_uri = config.get("SQLALCHEMY_DATABASE_URI")
     session.add(dbobj)
     session.commit()
@@ -68,7 +70,7 @@ def load_energy():
         },
         index=False)
 
-    print("Creating table [wb_health_population] reference")
+    logger.info("Creating table [wb_health_population] reference")
     tbl = db.session.query(TBL).filter_by(table_name=tbl_name).first()
     if not tbl:
         tbl = TBL(table_name=tbl_name)
@@ -130,7 +132,7 @@ def load_world_bank_health_n_pop():
         },
         index=False)
 
-    print("Creating table [wb_health_population] reference")
+    logger.info("Creating table [wb_health_population] reference")
     tbl = db.session.query(TBL).filter_by(table_name=tbl_name).first()
     if not tbl:
         tbl = TBL(table_name=tbl_name)
@@ -164,7 +166,7 @@ def load_world_bank_health_n_pop():
         "show_bubbles": "y",
     }
 
-    print("Creating slices")
+    logger.info("Creating slices")
     slices = [
         Slice(
             slice_name="Region Filter",
@@ -267,7 +269,7 @@ def load_world_bank_health_n_pop():
     for slc in slices:
         merge_slice(slc)
 
-    print("Creating a World's Health Bank dashboard")
+    logger.info("Creating a World's Health Bank dashboard")
     dash_name = "World's Health Bank Dashboard"
     dash = db.session.query(Dash).filter_by(dashboard_title=dash_name).first()
 
@@ -348,7 +350,7 @@ def load_world_bank_health_n_pop():
 
 def load_css_templates():
     """Loads 2 css templates to demonstrate the feature"""
-    print('Creating default CSS templates')
+    logger.info('Creating default CSS templates')
     CSS = models.CssTemplate  # noqa
 
     obj = db.session.query(CSS).filter_by(template_name='Flat').first()
@@ -464,10 +466,10 @@ def load_birth_names():
         },
         index=False)
     l = []
-    print("Done loading table!")
-    print("-" * 80)
+    logger.info("Done loading table!")
+    logger.info("-" * 80)
 
-    print("Creating table reference")
+    logger.info("Creating table reference")
     obj = db.session.query(TBL).filter_by(table_name='birth_names').first()
     if not obj:
         obj = TBL(table_name='birth_names')
@@ -499,7 +501,7 @@ def load_birth_names():
         "markup_type": "markdown",
     }
 
-    print("Creating some slices")
+    logger.info("Creating some slices")
     slices = [
         Slice(
             slice_name="Girls",
@@ -609,7 +611,7 @@ def load_birth_names():
     for slc in slices:
         merge_slice(slc)
 
-    print("Creating a dashboard")
+    logger.info("Creating a dashboard")
     dash = db.session.query(Dash).filter_by(dashboard_title="Births").first()
 
     if not dash:

caravel/models.py

@@ -38,6 +38,7 @@
 from caravel.viz import viz_types
 
 config = app.config
+logger = logging.getLogger(__name__)
 
 QueryResult = namedtuple('namedtuple', ['df', 'query', 'duration'])
 
@@ -188,7 +189,7 @@ def slice_url(self):
         try:
             slice_params = json.loads(self.params)
         except Exception as e:
-            logging.exception(e)
+            logger.exception(e)
             slice_params = {}
         slice_params['slice_id'] = self.id
         slice_params['slice_name'] = self.slice_name
@@ -928,7 +929,7 @@ def generate_metrics(self):
     @classmethod
     def sync_to_db(cls, name, cluster):
         """Fetches metadata for that datasource and merges the Caravel db"""
-        print("Syncing Druid datasource [{}]".format(name))
+        logger.info("Syncing Druid datasource [{}]".format(name))
         session = get_session()
         datasource = session.query(cls).filter_by(datasource_name=name).first()
         if not datasource:

caravel/utils.py

@@ -16,6 +16,11 @@
 from markdown import markdown as md
 from sqlalchemy.types import TypeDecorator, TEXT
 
+from caravel import app
+
+config = app.config
+logger = logging.getLogger(__name__)
+
 
 class memoized(object):  # noqa
 
@@ -87,7 +92,7 @@ def parse_human_datetime(s):
             cal = parsedatetime.Calendar()
             dttm = dttm_from_timtuple(cal.parse(s)[0])
         except Exception as e:
-            logging.exception(e)
+            logger.exception(e)
             raise ValueError("Couldn't parse date string [{}]".format(s))
     return dttm
 

caravel/views.py

@@ -30,13 +30,14 @@
 
 config = app.config
 log_this = models.Log.log_this
+logger = logging.getLogger(__name__)
 
 
 def validate_json(form, field):  # noqa
     try:
         json.loads(field.data)
     except Exception as e:
-        logging.exception(e)
+        logger.exception(e)
         raise ValidationError("json isn't valid")
 
 
@@ -194,7 +195,7 @@ def post_add(self, table):
         try:
             table.fetch_metadata()
         except Exception as e:
-            logging.exception(e)
+            logger.exception(e)
             flash(
                 "Table [{}] doesn't seem to exist, "
                 "couldn't fetch metadata".format(table.table_name),
@@ -403,7 +404,7 @@ class R(BaseView):
     def index(self, url_id):
         url = db.session.query(models.Url).filter_by(id=url_id).first()
         if url:
-            print(url.url)
+            logger.info(url.url)
             return redirect('/' + url.url)
         else:
             flash("URL to nowhere...", "danger")
@@ -484,7 +485,7 @@ def explore(self, datasource_type, datasource_id):
             try:
                 payload = obj.get_json()
             except Exception as e:
-                logging.exception(e)
+                logger.exception(e)
                 if config.get("DEBUG"):
                     raise e
                 payload = str(e)
@@ -793,7 +794,7 @@ def refresh_datasources(self):
                     "Error while processing cluster '{}'\n{}".format(
                         cluster, str(e)),
                     "danger")
-                logging.exception(e)
+                logger.exception(e)
                 return redirect('/druidclustermodelview/list/')
             cluster.metadata_last_refreshed = datetime.now()
             flash(

caravel/viz.py

@@ -27,6 +27,7 @@
 from caravel.forms import FormFactory
 
 config = app.config
+logger = logging.getLogger(__name__)
 
 
 class BaseViz(object):
@@ -239,7 +240,7 @@ def get_json(self):
             payload = cache.get(cache_key)
         if payload:
             is_cached = True
-            logging.info("Serving from cache")
+            logger.info("Serving from cache")
         else:
             is_cached = False
             cache_timeout = self.cache_timeout
@@ -253,7 +254,7 @@ def get_json(self):
                 'cache_timeout': cache_timeout,
             }
             payload['cached_dttm'] = datetime.now().isoformat().split('.')[0]
-            logging.info("Caching for the next {} seconds".format(
+            logger.info("Caching for the next {} seconds".format(
                 cache_timeout))
             cache.set(cache_key, payload, timeout=self.cache_timeout)
         payload['is_cached'] = is_cached