Add prediction logging to AWS Lambda deployment (#790)

* Repository and Deployment refactor and cleanup (#771)

* make sagemaker docker image have same file structure

* use consistent file names

* move operator code out of __init__ to avoid loading unused code in model server startup

* refactor deployment validator

* reorganize bento repository code

* deployment valiator test&linting error fix

* more repository code cleanup

* renaming and adding inline comments

* move out lambda operator code to separate file

* fix some typos + adding logging to lambda callback

* fix some linting problems

* fix mock not returning proper form

* add trailing comma

* add better logging + docs

* whitespace fixes

* move logging and consolidate debug line

* update docs + fixed logging

* fix linting issues

* remove redundant logging and switch to bento logger

* update docs

Co-authored-by: Chaoyu <paranoyang@gmail.com>
Co-authored-by: cory <cory.massaro@gmail.com>

bentoml/yatai/deployment/aws_lambda/lambda_app.py

@@ -14,6 +14,8 @@
 
 import os
 import sys
+import logging
+import json
 
 try:
     import download_extra_resources
@@ -38,18 +40,20 @@
 os.environ['BENTOML_HOME'] = '/tmp/bentoml/'
 from bentoml import load  # noqa
 
+logger = logging.getLogger('bentoml.lambda_app')
+
 bento_name = os.environ['BENTOML_BENTO_SERVICE_NAME']
 api_name = os.environ["BENTOML_API_NAME"]
 
 bento_bundle_path = os.path.join('./', bento_name)
 if not os.path.exists(bento_bundle_path):
     bento_bundle_path = os.path.join('/tmp/requirements', bento_name)
 
-print(f'Loading BentoService bundle from path: "{bento_bundle_path}"')
+logger.debug('Loading BentoService bundle from path: "%s"', bento_bundle_path)
 bento_service = load(bento_bundle_path)
-print(f'BentoService "{bento_service.name}" loaded successfully')
+logger.debug('BentoService "%s" loaded successfully', bento_service.name)
 bento_service_api = bento_service.get_service_api(api_name)
-print(f'BentoService API "{api_name}" loaded successfully')
+logger.debug('BentoService API "%s" loaded successfully', {api_name})
 
 this_module = sys.modules[__name__]
 
@@ -62,18 +66,34 @@ def api_func(event, context):  # pylint: disable=unused-argument
     Application Load Balancer, in which case the parameter `event` must be type `dict`
     containing the HTTP request headers and body.
 
-    see: https://docs.aws.amazon.com/lambda/latest/dg/services-alb.html
+    You can find an example of which
+    variables you can expect from the `event` object on the AWS Docs, here
+    https://docs.aws.amazon.com/lambda/latest/dg/services-alb.html
     """
 
     if type(event) is dict and "headers" in event and "body" in event:
-        return bento_service_api.handle_aws_lambda_event(event)
+        prediction = bento_service_api.handle_aws_lambda_event(event)
+        logger.info(
+            json.dumps(
+                {
+                    'event': event,
+                    'prediction': prediction["body"],
+                    'status_code': prediction["statusCode"],
+                }
+            )
+        )
+
+        if prediction["statusCode"] >= 400:
+            logger.warning('Error when predicting. Check logs for more information.')
+
+        return prediction
     else:
         error_msg = (
             'Error: Unexpected Lambda event data received. Currently BentoML lambda '
             'deployment can only handle event triggered by HTTP request from '
             'Application Load Balancer.'
         )
-        print(error_msg)
+        logger.error(error_msg)
         raise RuntimeError(error_msg)
 
 

bentoml/yatai/deployment/aws_lambda/operator.py

@@ -189,8 +189,10 @@ def _deploy_lambda_function(
         for i in artifact_types
     ) and (py_major, py_minor) != ('3', '6'):
         raise BentoMLException(
-            'For Tensorflow and Keras model, only python3.6 is '
-            'supported for AWS Lambda deployment'
+            'AWS Lambda Deployment only supports BentoML services'
+            'built with Python 3.6.x. To fix this, repack your'
+            'service with the right Python version'
+            '(hint: pyenv/anaconda) and try again'
         )
 
     api_names = (

bentoml/yatai/deployment/aws_lambda/utils.py

@@ -201,7 +201,7 @@ def init_sam_project(
     function_path = os.path.join(sam_project_path, deployment_name)
     os.mkdir(function_path)
     # Copy requirements.txt
-    logger.debug('Coping requirements.txt')
+    logger.debug('Copying requirements.txt')
     requirement_txt_path = os.path.join(bento_service_bundle_path, 'requirements.txt')
     shutil.copy(requirement_txt_path, function_path)
 
@@ -210,7 +210,7 @@ def init_sam_project(
     )
     if os.path.isdir(bundled_dep_path):
         # Copy bundled pip dependencies
-        logger.debug('Coping bundled_dependencies')
+        logger.debug('Copying bundled_dependencies')
         shutil.copytree(
             bundled_dep_path, os.path.join(function_path, 'bundled_pip_dependencies')
         )
@@ -232,7 +232,7 @@ def init_sam_project(
             requirement_file.writelines(required_modules)
 
     # Copy bento_service_model
-    logger.debug('Coping model directory')
+    logger.debug('Copying model directory')
     model_path = os.path.join(bento_service_bundle_path, bento_name)
     shutil.copytree(model_path, os.path.join(function_path, bento_name))
 

docs/source/deployment/aws_lambda.rst

@@ -201,9 +201,101 @@ Use `bentoml lambda list` to have a quick glance of all of the AWS Lambda deploy
     NAME                        NAMESPACE    LABELS    PLATFORM    STATUS    AGE
     my-first-lambda-deployment  dev                    aws-lambda  running   8 minutes and 49.6 seconds
 
+If you need to look at the logs of your deployed model, we can view these within AWS CloudWatch. You can get here by searching up `CloudWatch` in your AWS Console. Then, on the left panel, click `Logs > Log Groups` and select your Lambda deployment. The name should be of the form `/aws/lambda/dev-{name}` where `{name}` is the name you used when you deployed it using the CLI. Here, you can look at specific instances of your Lambda function and the logs within it. A typical prediction may look something like the following
 
+.. code-block:: none
 
-Remove Lambda deployment is also very easy.  Calling `bentoml lambda delete` command will delete the Lambda function and related AWS resources
+    ...
+    START RequestId: 11ee8a7a-9884-454a-b008-fd814d9b1781 Version: $LATEST
+    [INFO] 2020-06-14T02:13:26.439Z 11ee8a7a-9884-454a-b008-fd814d9b1781 {"event": {"resource": "/predict", "path": "/predict", ...
+    END RequestId: 11ee8a7a-9884-454a-b008-fd814d9b1781
+    REPORT RequestId: 11ee8a7a-9884-454a-b008-fd814d9b1781 Duration: 14.97 ms Billed Duration: 100 ms Memory Size: 1024 MB...
+    ...
+
+If you'd like to have some more detailed analytics into your logs, you may notice that we log some more detailed JSON data as debug info. There are three main fields that are logged. `event` (AWS Lambda Event Object), `prediction` (response body), and `status_code` (HTTP Response Code). You can read more about the `event` object here: https://docs.aws.amazon.com/lambda/latest/dg/services-alb.html. An example of the prediction JSON is as follows,
+
+.. code-block:: bash
+
+    {
+        "event": {
+            "resource": "/predict",
+            "path": "/predict",
+            "httpMethod": "POST",
+            "headers": {
+                "Accept": "*/*",
+                "Accept-Encoding": "gzip, deflate, br",
+                "Cache-Control": "no-cache",
+                "CloudFront-Forwarded-Proto": "https",
+                "CloudFront-Is-Desktop-Viewer": "true",
+                "CloudFront-Is-Mobile-Viewer": "false",
+                "CloudFront-Is-SmartTV-Viewer": "false",
+                "CloudFront-Is-Tablet-Viewer": "false",
+                "CloudFront-Viewer-Country": "CA",
+                "Content-Type": "application/json",
+                "Host": "w3y4nf55k0.execute-api.us-east-2.amazonaws.com",
+                "Postman-Token": "f785223c-e600-4eea-84a2-8215ebe1afaa",
+                "Via": "1.1 98aedae6661e3904540676966998ed89.cloudfront.net (CloudFront)",
+                "X-Amz-Cf-Id": "K1cd5UVt__3WEj7DI8kfbi1V5MM4a-v2bRm1Y0kq-mHoOCeCsF_ahg==",
+                "X-Amzn-Trace-Id": "Root=1-5ee80803-20ab0d226a290900e7f3d334",
+                "X-Forwarded-For": "96.49.202.214, 64.252.141.139",
+                "X-Forwarded-Port": "443",
+                "X-Forwarded-Proto": "https"
+            },
+            "multiValueHeaders": {
+              ...
+            },
+            "queryStringParameters": null,
+            "multiValueQueryStringParameters": null,
+            "pathParameters": null,
+            "stageVariables": null,
+            "requestContext": {
+                "resourceId": "7vnchj",
+                "resourcePath": "/predict",
+                "httpMethod": "POST",
+                "extendedRequestId": "OMYwiHX4iYcF4Zg=",
+                "requestTime": "15/Jun/2020:23:45:07 +0000",
+                "path": "/Prod/predict",
+                "accountId": "558447057402",
+                "protocol": "HTTP/1.1",
+                "stage": "Prod",
+                "domainPrefix": "w3y4nf55k0",
+                "requestTimeEpoch": 1592264707383,
+                "requestId": "57e19330-67af-4d68-8bb9-4418acb8e880",
+                "identity": {
+                    "cognitoIdentityPoolId": null,
+                    "accountId": null,
+                    "cognitoIdentityId": null,
+                    "caller": null,
+                    "sourceIp": "96.49.202.214",
+                    "principalOrgId": null,
+                    "accessKey": null,
+                    "cognitoAuthenticationType": null,
+                    "cognitoAuthenticationProvider": null,
+                    "userArn": null,
+                    "userAgent": "PostmanRuntime/7.25.0",
+                    "user": null
+                },
+                "domainName": "w3y4nf55k0.execute-api.us-east-2.amazonaws.com",
+                "apiId": "w3y4nf55k0"
+            },
+            "body": "[[5.1, 3.5, 1.4, 0.2]]",
+            "isBase64Encoded": false
+        },
+        "prediction": "[0]",
+        "status_code": 200
+    }
+
+You can parse this JSON using CloudWatch Logs Insights or ElasticSearch. Within Logs Insights, you can construct a query to visualize the logs that match certain criteria. If, for example, you wanted to view all predictions the returned with a status code of 200, the query would look something like
+
+.. code-block:: none
+
+    fields @timestamp, @message, status_code
+    | sort @timestamp desc
+    | filter status_code = 200
+
+In this example, `@timestamp` and `@message` represent the time when the log was emitted and the full log message. The third field can be any first level JSON field that were logged (either event info or prediction info).
+
+Removing a Lambda deployment is also very easy.  Calling `bentoml lambda delete` command will delete the Lambda function and related AWS resources
 
 .. code-block:: bash
 

tests/deployment/aws_lambda/test_aws_lambda_deployment_operator.py

@@ -56,7 +56,7 @@ def generate_lambda_deployment_pb():
 
 def test_aws_lambda_app_py(monkeypatch):
     def test_predict(value):
-        return value['body']
+        return {'body': value['body'], 'statusCode': 200}
 
     class Mock_bento_service_class(object):
         name = "mock_bento_service"
@@ -106,7 +106,10 @@ def return_predict_func(mock_load_service):
     with pytest.raises(RuntimeError):
         predict("Invalid Input Type", None)
 
-    assert predict({"headers": [], "body": 'test'}, None) == 'test'
+    assert predict({"headers": [], "body": 'test'}, None) == {
+        'body': 'test',
+        'statusCode': 200,
+    }
 
 
 @patch('shutil.rmtree', MagicMock())