diff --git a/atst/utils/logging.py b/atst/utils/logging.py index 5cc8e90d..d2370558 100644 --- a/atst/utils/logging.py +++ b/atst/utils/logging.py @@ -35,7 +35,7 @@ class JsonFormatter(logging.Formatter): ] def format(self, record): - message_dict = {} + message_dict = {"source": "atst"} for field, func in self._DEFAULT_RECORD_FIELDS: message_dict[field] = func(record) diff --git a/deploy/kubernetes/atst-configmap.yml b/deploy/kubernetes/atst-configmap.yml index a9584fc5..79f9a61b 100644 --- a/deploy/kubernetes/atst-configmap.yml +++ b/deploy/kubernetes/atst-configmap.yml @@ -10,6 +10,26 @@ data: callable = app module = app socket = /var/run/uwsgi/uwsgi.socket - plugins = python3 + plugin = python3 + plugin = logfile virtualenv = /opt/atat/atst/.venv chmod-socket = 666 + + ; logger config + + ; application logs: log without modifying + logger = secondlogger stdio + log-route = secondlogger atst + log-encoder = format:secondlogger ${msg} + + ; default uWSGI messages (start, stop, etc.) + logger = default stdio + log-route = default ^((?!atst).)*$ + log-encoder = json:default {"timestamp":"${strftime:%%FT%%T}","source":"uwsgi","severity":"DEBUG","message":"${msg}"} + log-encoder = nl + + ; uWSGI request logs + logger-req = stdio + log-format = request_id=%(var.HTTP_X_REQUEST_ID), pid=%(pid), remote_add=%(addr), request=%(method) %(uri), status=%(status), body_bytes_sent=%(rsize), referer=%(referer), user_agent=%(uagent), http_x_forwarded_for=%(var.HTTP_X_FORWARDED_FOR) + log-req-encoder = json {"timestamp":"${strftime:%%FT%%T}","source":"req","severity":"INFO","message":"${msg}"} + log-req-encoder = nl diff --git a/deploy/kubernetes/atst-envvars-configmap.yml b/deploy/kubernetes/atst-envvars-configmap.yml index 5e5a1fb1..39b09ad3 100644 --- a/deploy/kubernetes/atst-envvars-configmap.yml +++ b/deploy/kubernetes/atst-envvars-configmap.yml @@ -10,3 +10,4 @@ data: OVERRIDE_CONFIG_FULLPATH: /opt/atat/atst/atst-overrides.ini UWSGI_CONFIG_FULLPATH: /opt/atat/atst/uwsgi-config.ini CRL_STORAGE_PROVIDER: CLOUDFILES + LOG_JSON: "true" diff --git a/deploy/kubernetes/test/atst-configmap.yml b/deploy/kubernetes/test/atst-configmap.yml index 54409d7d..30c64f29 100644 --- a/deploy/kubernetes/test/atst-configmap.yml +++ b/deploy/kubernetes/test/atst-configmap.yml @@ -10,6 +10,26 @@ data: callable = app module = app socket = /var/run/uwsgi/uwsgi.socket - plugins = python3 + plugin = python3 + plugin = logfile virtualenv = /opt/atat/atst/.venv chmod-socket = 666 + + ; logger config + + ; application logs: log without modifying + logger = secondlogger stdio + log-route = secondlogger atst + log-encoder = format:secondlogger ${msg} + + ; default uWSGI messages (start, stop, etc.) + logger = default stdio + log-route = default ^((?!atst).)*$ + log-encoder = json:default {"timestamp":"${strftime:%%FT%%T}","source":"uwsgi","severity":"DEBUG","message":"${msg}"} + log-encoder = nl + + ; uWSGI request logs + logger-req = stdio + log-format = request_id=%(var.HTTP_X_REQUEST_ID), pid=%(pid), remote_add=%(addr), request=%(method) %(uri), status=%(status), body_bytes_sent=%(rsize), referer=%(referer), user_agent=%(uagent), http_x_forwarded_for=%(var.HTTP_X_FORWARDED_FOR) + log-req-encoder = json {"timestamp":"${strftime:%%FT%%T}","source":"req","severity":"INFO","message":"${msg}"} + log-req-encoder = nl diff --git a/deploy/kubernetes/test/atst-envvars-configmap.yml b/deploy/kubernetes/test/atst-envvars-configmap.yml index 67f1d226..bc82c333 100644 --- a/deploy/kubernetes/test/atst-envvars-configmap.yml +++ b/deploy/kubernetes/test/atst-envvars-configmap.yml @@ -11,3 +11,4 @@ data: UWSGI_CONFIG_FULLPATH: /opt/atat/atst/uwsgi-config.ini RQ_QUEUES: atat-test CRL_STORAGE_PROVIDER: CLOUDFILES + LOG_JSON: "true" diff --git a/deploy/kubernetes/test/test.yml b/deploy/kubernetes/test/test.yml index 3c1c3bc0..82c64dd0 100644 --- a/deploy/kubernetes/test/test.yml +++ b/deploy/kubernetes/test/test.yml @@ -28,7 +28,7 @@ spec: fsGroup: 101 containers: - name: atst - image: registry.atat.codes:443/atst-prod:47ce80b4 + image: registry.atat.codes:443/atst-prod:575cfce5 resources: requests: memory: "2500Mi" @@ -155,7 +155,7 @@ spec: fsGroup: 101 containers: - name: atst-worker - image: registry.atat.codes:443/atst-prod:47ce80b4 + image: registry.atat.codes:443/atst-prod:575cfce5 args: ["/bin/bash", "-c", "/opt/atat/atst/script/rq_worker"] resources: requests: diff --git a/deploy/kubernetes/uat/atst-configmap.yml b/deploy/kubernetes/uat/atst-configmap.yml index f7a8a9ca..0482ea10 100644 --- a/deploy/kubernetes/uat/atst-configmap.yml +++ b/deploy/kubernetes/uat/atst-configmap.yml @@ -10,6 +10,26 @@ data: callable = app module = app socket = /var/run/uwsgi/uwsgi.socket - plugins = python3 + plugin = python3 + plugin = logfile virtualenv = /opt/atat/atst/.venv chmod-socket = 666 + + ; logger config + + ; application logs: log without modifying + logger = secondlogger stdio + log-route = secondlogger atst + log-encoder = format:secondlogger ${msg} + + ; default uWSGI messages (start, stop, etc.) + logger = default stdio + log-route = default ^((?!atst).)*$ + log-encoder = json:default {"timestamp":"${strftime:%%FT%%T}","source":"uwsgi","severity":"DEBUG","message":"${msg}"} + log-encoder = nl + + ; uWSGI request logs + logger-req = stdio + log-format = request_id=%(var.HTTP_X_REQUEST_ID), pid=%(pid), remote_add=%(addr), request=%(method) %(uri), status=%(status), body_bytes_sent=%(rsize), referer=%(referer), user_agent=%(uagent), http_x_forwarded_for=%(var.HTTP_X_FORWARDED_FOR) + log-req-encoder = json {"timestamp":"${strftime:%%FT%%T}","source":"req","severity":"INFO","message":"${msg}"} + log-req-encoder = nl diff --git a/deploy/kubernetes/uat/atst-envvars-configmap.yml b/deploy/kubernetes/uat/atst-envvars-configmap.yml index e7afea02..7821b5c0 100644 --- a/deploy/kubernetes/uat/atst-envvars-configmap.yml +++ b/deploy/kubernetes/uat/atst-envvars-configmap.yml @@ -11,3 +11,4 @@ data: UWSGI_CONFIG_FULLPATH: /opt/atat/atst/uwsgi-config.ini RQ_QUEUES: atat-uat CRL_STORAGE_PROVIDER: CLOUDFILES + LOG_JSON: "true" diff --git a/sample-server/Procfile b/sample-server/Procfile new file mode 100644 index 00000000..a03656c7 --- /dev/null +++ b/sample-server/Procfile @@ -0,0 +1,2 @@ +uwsgi: LOG_JSON=true DEBUG=false uwsgi --ini sample-server/uwsgi.ini +nginx: nginx -c $(pwd)/sample-server/nginx.conf diff --git a/sample-server/README b/sample-server/README new file mode 100644 index 00000000..7e0407f4 --- /dev/null +++ b/sample-server/README @@ -0,0 +1,17 @@ +# Sample Server + +## Requirements + +- [nginx](https://www.nginx.com/resources/wiki/start/topics/tutorials/install/): On macos with homebrew, `brew install nginx` +- [uwsgi](https://uwsgi-docs.readthedocs.io/en/latest/Install.html): With python, `pip install uwsgi`. +- pipenv and honcho: If you have the regular atst dependencies installed, you already have pipenv and honcho + +## Run + +The sample server runs at localhost:8000, so you cannot have another copy of the app running on that port. + +Start both NGINX and uWSGI with honcho: + +``` +pipenv run honcho start -f sample-server/Procfile +``` diff --git a/sample-server/nginx.conf b/sample-server/nginx.conf new file mode 100644 index 00000000..07a63084 --- /dev/null +++ b/sample-server/nginx.conf @@ -0,0 +1,61 @@ +worker_processes 1; + +daemon off; + +error_log /dev/stdout; + +events { + worker_connections 1024; +} + +http { + default_type application/octet-stream; + log_format json escape=json + '{' + '"timestamp":"$time_iso8601",' + '"msec":"$msec",' + '"request_id":"$request_id",' + '"remote_addr":"$remote_addr",' + '"remote_user":"$remote_user",' + '"request":"$request",' + '"status":$status,' + '"body_bytes_sent":$body_bytes_sent,' + '"referer":"$http_referer",' + '"user_agent":"$http_user_agent",' + '"http_x_forwarded_for":"$http_x_forwarded_for"' + '}'; + + keepalive_timeout 65; + + server { + listen 8000; + server_name localhost; + + access_log /dev/stdout json; + + location / { + try_files $uri @app; + } + + location @app { + uwsgi_pass uwsgi://localhost:8080; + uwsgi_param QUERY_STRING $query_string; + uwsgi_param REQUEST_METHOD $request_method; + uwsgi_param CONTENT_TYPE $content_type; + uwsgi_param CONTENT_LENGTH $content_length; + + uwsgi_param REQUEST_URI $request_uri; + uwsgi_param PATH_INFO $document_uri; + uwsgi_param DOCUMENT_ROOT $document_root; + uwsgi_param SERVER_PROTOCOL $server_protocol; + uwsgi_param REQUEST_SCHEME $scheme; + uwsgi_param HTTPS $https if_not_empty; + + uwsgi_param REMOTE_ADDR $remote_addr; + uwsgi_param REMOTE_PORT $remote_port; + uwsgi_param SERVER_PORT $server_port; + uwsgi_param SERVER_NAME $server_name; + uwsgi_param HTTP_X_REQUEST_ID $request_id; + } + } +} diff --git a/sample-server/uwsgi.ini b/sample-server/uwsgi.ini new file mode 100644 index 00000000..daf040bb --- /dev/null +++ b/sample-server/uwsgi.ini @@ -0,0 +1,26 @@ +[uwsgi] +; general uWSGI config for sample +callable = app +module = app +plugin = python3 +plugin = stdio +socket = localhost:8080 + +; logger config + +; application logs: log without modifying +logger = secondlogger stdio +log-route = secondlogger atst +log-encoder = format:secondlogger ${msg} + +; default uWSGI messages (start, stop, etc.) +logger = default stdio +log-route = default ^((?!atst).)*$ +log-encoder = json:default {"timestamp":"${strftime:%%FT%%T}","source":"uwsgi","severity":"DEBUG","message":"${msg}"} +log-encoder = nl + +; uWSGI request logs +logger-req = stdio +log-format = request_id=%(var.HTTP_X_REQUEST_ID), pid=%(pid), remote_add=%(addr), request=%(method) %(uri), status=%(status), body_bytes_sent=%(rsize), referer=%(referer), user_agent=%(uagent), http_x_forwarded_for=%(var.HTTP_X_FORWARDED_FOR) +log-req-encoder = json {"timestamp":"${strftime:%%FT%%T}","source":"req","severity":"INFO","message":"${msg}"} +log-req-encoder = nl