don't capture logs directly from stdout

previously in run_app_paas.sh, we captured stdout from the app and
piped that into the log file. However, this came up with a bunch of
problems, mainly:

* exceptions with stack traces often weren't formatted properly,
  and kibana could not parse them
* celery logs were duplicated - we'd collect both the json logs and
  the human readable stdout logs.

instead, with the updated utils library, we can use that to log json
straight to the appropriate directory directly.

app/cloudfoundry_config.py

@@ -18,7 +18,7 @@ def set_config_env_vars(vcap_services):
 
     vcap_application = json.loads(os.environ['VCAP_APPLICATION'])
     os.environ['NOTIFY_ENVIRONMENT'] = vcap_application['space_name']
-    os.environ['LOGGING_STDOUT_JSON'] = '1'
+    os.environ['NOTIFY_LOG_PATH'] = '/home/vcap/logs/app.log'
 
     # Notify common config
     for s in vcap_services['user-provided']:

app/config.py

@@ -95,7 +95,6 @@ class Config(object):
 
     # Logging
     DEBUG = False
-    LOGGING_STDOUT_JSON = os.getenv('LOGGING_STDOUT_JSON') == '1'
 
     ###########################
     # Default config values ###
@@ -106,7 +105,7 @@ class Config(object):
     AWS_REGION = 'eu-west-1'
     INVITATION_EXPIRATION_DAYS = 2
     NOTIFY_APP_NAME = 'api'
-    NOTIFY_LOG_PATH = '/var/log/notify/application.log'
+    NOTIFY_LOG_PATH = None
     SQLALCHEMY_COMMIT_ON_TEARDOWN = False
     SQLALCHEMY_RECORD_QUERIES = True
     SQLALCHEMY_TRACK_MODIFICATIONS = True
@@ -277,6 +276,7 @@ class Config(object):
 ######################
 
 class Development(Config):
+    NOTIFY_LOG_PATH = 'application.log'
     SQLALCHEMY_ECHO = False
     NOTIFY_EMAIL_DOMAIN = 'notify.tools'
     CSV_UPLOAD_BUCKET_NAME = 'development-notifications-csv-upload'

requirements.txt

@@ -28,6 +28,6 @@ notifications-python-client>=3.1,<3.2
 awscli>=1.11,<1.12
 awscli-cwlogs>=1.4,<1.5
 
-git+https://github.com/alphagov/notifications-utils.git@17.8.0#egg=notifications-utils==17.8.0
+git+https://github.com/alphagov/notifications-utils.git@18.0.0#egg=notifications-utils==18.0.0
 
 git+https://github.com/alphagov/boto.git@2.43.0-patch3#egg=boto==2.43.0-patch3

scripts/run_app_paas.sh

@@ -52,11 +52,9 @@ function on_exit {
   kill 0
 }
 
-function start_appplication {
-  exec "$@" 2>&1 | while read line; do echo $line; echo $line >> /home/vcap/logs/app.log.`date +%Y-%m-%d`; done &
-  LOGGER_PID=$!
+function start_application {
+  exec "$@" &
   APP_PID=`jobs -p`
-  echo "Logger process pid: ${LOGGER_PID}"
   echo "Application process pid: ${APP_PID}"
 }
 
@@ -69,7 +67,6 @@ function start_aws_logs_agent {
 function run {
   while true; do
     kill -0 ${APP_PID} 2&>/dev/null || break
-    kill -0 ${LOGGER_PID} 2&>/dev/null || break
     kill -0 ${AWSLOGS_AGENT_PID} 2&>/dev/null || start_aws_logs_agent
     sleep 1
   done
@@ -84,7 +81,7 @@ trap "on_exit" EXIT
 configure_aws_logs
 
 # The application has to start first!
-start_appplication "$@"
+start_application "$@"
 
 start_aws_logs_agent
 

tests/app/test_cloudfoundry_config.py

@@ -122,8 +122,8 @@ def test_extract_cloudfoundry_config_populates_other_vars():
     extract_cloudfoundry_config()
 
     assert os.environ['SQLALCHEMY_DATABASE_URI'] == 'postgres uri'
-    assert os.environ['LOGGING_STDOUT_JSON'] == '1'
     assert os.environ['NOTIFY_ENVIRONMENT'] == '🚀🌌'
+    assert os.environ['NOTIFY_LOG_PATH'] == '/home/vcap/logs/app.log'
 
 
 @pytest.mark.usefixtures('os_environ', 'cloudfoundry_environ')

tests/app/test_config.py

@@ -57,24 +57,3 @@ def test_load_config_if_cloudfoundry_not_available(monkeypatch, reload_config):
 def test_cloudfoundry_config_has_different_defaults():
     # these should always be set on Sandbox
     assert config.Sandbox.REDIS_ENABLED is False
-
-
-def test_logging_stdout_json_defaults_to_off(reload_config):
-    os.environ.pop('LOGGING_STDOUT_JSON', None)
-    assert config.Config.LOGGING_STDOUT_JSON is False
-
-
-def test_logging_stdout_json_sets_to_off_if_not_recognised(reload_config):
-    os.environ['LOGGING_STDOUT_JSON'] = 'foo'
-
-    importlib.reload(config)
-
-    assert config.Config.LOGGING_STDOUT_JSON is False
-
-
-def test_logging_stdout_json_sets_to_on_if_set_to_1(reload_config):
-    os.environ['LOGGING_STDOUT_JSON'] = '1'
-
-    importlib.reload(config)
-
-    assert config.Config.LOGGING_STDOUT_JSON is True