Add debug mode for prediction requests (#369)

Author: 1vn

cli/cmd/get.go

@@ -288,6 +288,7 @@ func describeAPI(name string, resourcesRes *schema.GetResourcesResponse, flagVer
 	apiEndpoint := urls.Join(resourcesRes.APIsBaseURL, anyAPIStatus.Path)
 
 	out := "\n" + console.Bold("url:  ") + apiEndpoint + "\n"
+	out += "\n" + console.Bold("debug url:  ") + apiEndpoint + "?debug=true" + "\n\n"
 	out += fmt.Sprintf("%s curl -X POST -H \"Content-Type: application/json\" %s -d @samples.json\n", console.Bold("curl:"), apiEndpoint)
 	out += fmt.Sprintf(console.Bold("updated at:")+" %s\n\n", libtime.LocalTimestamp(updatedAt))
 

cli/cmd/predict.go

@@ -31,9 +31,12 @@ import (
 	"github.com/cortexlabs/cortex/pkg/operator/api/resource"
 )
 
+var predictDebug bool
+
 func init() {
 	addAppNameFlag(predictCmd)
 	addEnvFlag(predictCmd)
+	predictCmd.Flags().BoolVar(&predictDebug, "debug", false, "Predict with debug mode")
 }
 
 type PredictResponse struct {
@@ -80,6 +83,9 @@ var predictCmd = &cobra.Command{
 
 		apiPath := apiGroupStatus.ActiveStatus.Path
 		apiURL := urls.Join(resourcesRes.APIsBaseURL, apiPath)
+		if predictDebug {
+			apiURL += "?debug=true"
+		}
 		predictResponse, err := makePredictRequest(apiURL, samplesJSONPath)
 		if err != nil {
 			if strings.Contains(err.Error(), "503 Service Temporarily Unavailable") || strings.Contains(err.Error(), "502 Bad Gateway") {

docs/deployments/apis.md

@@ -43,3 +43,12 @@ See [packaging models](packaging-models.md) for how to export the model.
 Request handlers are used to decouple the interface of an API endpoint from its model. A `pre_inference` request handler can be used to modify request payloads before they are sent to the model. A `post_inference` request handler can be used to modify model predictions in the server before they are sent to the client.
 
 See [request handlers](request-handlers.md) for a detailed guide.
+
+## Debugging
+
+You can log more information about each request by adding a `?debug=true` parameter to your requests. This will print:
+
+1. The raw sample
+2. The value after running the `pre_inference` function (if applicable)
+3. The value after running inference
+4. The value after running the `post_inference` function (if applicable)

pkg/workloads/cortex/lib/log.py

@@ -13,6 +13,7 @@
 # limitations under the License.
 
 import logging
+from cortex.lib import stringify
 
 logger = logging.getLogger("cortex")
 handler = logging.StreamHandler()
@@ -21,5 +22,12 @@
 logger.setLevel(logging.DEBUG)
 
 
+def debug_obj(name, sample, debug):
+    if not debug:
+        return
+
+    logger.info("{}: {}".format(name, stringify.truncate(sample)))
+
+
 def get_logger():
     return logging.getLogger("cortex")

pkg/workloads/cortex/lib/package.py

@@ -132,7 +132,8 @@ def build(args):
     ctx.upload_resource_status_start(*python_packages_list)
     try:
         build_packages(python_packages, ctx.storage)
-        util.log_job_finished(ctx.workload_id)
+        timestamp = util.now_timestamp_rfc_3339()
+        logger.info("workload: {}, completed: {}".format(ctx.workload_id, timestamp))
     except CortexException as e:
         e.wrap("error")
         logger.exception(e)

pkg/workloads/cortex/lib/stringify.py

@@ -0,0 +1,55 @@
+# Copyright 2019 Cortex Labs, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+from collections.abc import Iterable
+
+
+def truncate(item, max_elements=10, max_str_len=500):
+    if isinstance(item, str):
+        s = item
+        if max_str_len > 3 and len(s) > max_str_len:
+            s = s[: max_str_len - 3] + "..."
+        return '"{}"'.format(s)
+
+    if isinstance(item, dict):
+        count = 0
+        item_strs = []
+        for key in item:
+            if max_elements > 0 and count >= max_elements:
+                item_strs.append("...")
+                break
+
+            key_str = truncate(key, max_elements, max_str_len)
+            val_str = truncate(item[key], max_elements, max_str_len)
+            item_strs.append("{}: {}".format(key_str, val_str))
+            count += 1
+
+        return "{" + ", ".join(item_strs) + "}"
+
+    if isinstance(item, Iterable) and hasattr(item, "__getitem__"):
+        item_strs = []
+
+        for element in item[:max_elements]:
+            item_strs.append(truncate(element, max_elements, max_str_len))
+
+        if max_elements > 0 and len(item) > max_elements:
+            item_strs.append("...")
+
+        return "[" + ", ".join(item_strs) + "]"
+
+    # Fallback
+    s = str(item)
+    if max_str_len > 3 and len(s) > max_str_len:
+        s = s[: max_str_len - 3] + "..."
+    return s

pkg/workloads/cortex/lib/test/util_test.py

@@ -64,46 +64,3 @@ def test_is_number_col():
     assert util.is_number_col([None, 1, None])
     assert util.is_number_col([None, 1.1, None])
     assert not util.is_number_col([None, None, None])
-
-
-def test_print_samples_horiz(caplog):
-    caplog.set_level(logging.INFO)
-
-    samples = [
-        {
-            "test1": float(120),
-            "test2": 0.2,
-            "testlongstring": 0.20,
-            "a": 0.23,
-            "b": 0.233333333333333333,
-        },
-        {
-            "test1": 11,
-            "test2": 18,
-            "testreallyreallyreallyreallyreallylongstring": 18,
-            "a": -12,
-            "b": 10,
-        },
-        {
-            "test1": 13,
-            "test2": 13,
-            "testlongstring": 13,
-            "testreallyreallyreallyreallyreallylongstring": 13,
-            "a": 133333,
-            "b": None,
-        },
-    ]
-    util.print_samples_horiz(samples)
-
-    records = [r.message for r in caplog.records]
-
-    expected = (
-        "a:                      0.23, -12, 133333\n"
-        "b:                      0.23,  10,\n"
-        "test1:                120.00,  11,     13\n"
-        "test2:                  0.20,  18,     13\n"
-        "testlongstring:         0.20,    ,     13\n"
-        "testreallyreallyr...:       ,  18,     13\n"
-    )
-
-    assert "\n".join(records) + "\n" == expected

pkg/workloads/cortex/lib/util.py

@@ -16,7 +16,6 @@
 import errno
 import shutil
 import stat
-import pprint
 import pickle
 import json
 import collections
@@ -28,7 +27,7 @@
 from datetime import datetime
 
 from cortex.lib.log import get_logger
-
+from cortex.lib import stringify
 import json_tricks
 
 
@@ -39,64 +38,12 @@ def isclose(a, b, rel_tol=1e-09, abs_tol=0.0):
     return abs(a - b) <= max(rel_tol * max(abs(a), abs(b)), abs_tol)
 
 
-def indent_str(text, indent):
-    if not is_str(text):
-        text = repr(text)
-    return indent * " " + text.replace("\n", "\n" + indent * " ")
-
-
-def json_tricks_dump(obj, **kwargs):
-    return json_tricks.dumps(obj, primitives=True, **kwargs)
-
-
 def json_tricks_encoder(*args, **kwargs):
     kwargs["primitives"] = True
     kwargs["obj_encoders"] = json_tricks.nonp.DEFAULT_ENCODERS
     return json_tricks.TricksEncoder(*args, **kwargs)
 
 
-def pp_str(obj, indent=0):
-    try:
-        out = json_tricks_dump(obj, sort_keys=True, indent=2)
-    except:
-        out = pprint.pformat(obj, width=120)
-    return indent_str(out, indent)
-
-
-def pp(obj, indent=0):
-    print(pp_str(obj, indent))
-
-
-def pp_str_flat(obj, indent=0):
-    try:
-        out = json_tricks_dump(obj, sort_keys=True)
-    except:
-        out = str(obj).replace("\n", "")
-    return indent_str(out, indent)
-
-
-def user_obj_str(obj):
-    return truncate_str(pp_str_flat(obj), 1000)
-
-
-def log_indent(obj, indent=0, logging_func=logger.info):
-    if not is_str(obj):
-        text = repr(obj)
-    else:
-        text = obj
-    logging_func(indent_str(text, indent))
-
-
-def log_pretty(obj, indent=0, logging_func=logger.info):
-    formatted_str = pp_str(obj, indent)
-    for line in formatted_str.split("\n"):
-        logging_func(line)
-
-
-def log_pretty_flat(obj, indent=0, logging_func=logger.info):
-    logging_func(pp_str_flat(obj, indent))
-
-
 def pluralize(num, singular, plural):
     if num == 1:
         return str(num) + " " + singular
@@ -545,51 +492,6 @@ def extract_zip(zip_path, dest_dir=None, delete_zip_file=False):
         rm_file(zip_path)
 
 
-def print_samples_horiz(
-    samples, truncate=20, sep=",", first_sep=":", pad=1, first_pad=None, key_list=None
-):
-    if first_pad is None:
-        first_pad = pad
-
-    if not key_list:
-        field_names = sorted(list(set(flatten([list(sample.keys()) for sample in samples]))))
-    else:
-        field_names = key_list
-
-    rows = []
-    for field_name in field_names:
-        rows.append([field_name] + [sample.get(field_name, None) for sample in samples])
-
-    rows_strs = []
-    for row in rows:
-        row_strs = []
-        for i, item in enumerate(row):
-            row_strs.append(str_rep(item, truncate))
-        rows_strs.append(row_strs)
-
-    max_lens = []
-    for i in range(len(rows_strs[0])):
-        max_lens.append(max_len([row[i] for row in rows_strs]))
-
-    types = []
-    for i in range(len(rows[0])):
-        types.append(is_number_col([row[i] for row in rows]))
-
-    for row_strs in rows_strs:
-        row_str = ""
-        for i, item in enumerate(row_strs):
-            if i == 0:
-                row_str += pad_smart(item + first_sep, max_lens[i] + len(first_sep), types[i])
-                row_str += " " * first_pad
-            elif i == len(row_strs) - 1:
-                row_str += pad_smart(item, max_lens[i], types[i]).rstrip()
-            else:
-                row_str += pad_smart(item + sep, max_lens[i] + len(sep), types[i])
-                row_str += " " * pad
-
-        logger.info(row_str.strip())
-
-
 def max_len(strings):
     return max(len(s) for s in strings)
 
@@ -609,24 +511,6 @@ def pad_left(string, width):
     return string.rjust(width)
 
 
-def str_rep(item, truncate=20, round=2):
-    if item is None:
-        return ""
-    if is_float(item):
-        out = "{0:.2f}".format(item)
-    else:
-        out = str(item)
-
-    return truncate_str(out, truncate)
-
-
-def truncate_str(item, truncate=20):
-    if is_str(item) and truncate is not None and truncate > 3 and len(item) > truncate:
-        trim = truncate - 3
-        return item[:trim] + "..."
-    return item
-
-
 def is_number_col(items):
     if all(item is None for item in items):
         return False
@@ -638,11 +522,6 @@ def is_number_col(items):
     return True
 
 
-def log_job_finished(workload_id):
-    timestamp = now_timestamp_rfc_3339()
-    logger.info("workload: {}, completed: {}".format(workload_id, timestamp))
-
-
 def has_function(impl, fn_name):
     fn = getattr(impl, fn_name, None)
     if fn is None: