Enable logging (#118)

* logging setup

* add logging for http calls

* fix linter

* read logging configuration from config file

* fix linter

* using package name

Author: NRHelmi

railib/api.py

@@ -19,6 +19,7 @@
 import time
 import re
 import io
+import logging
 from enum import Enum, unique
 from typing import List, Union
 from requests_toolbelt import multipart
@@ -34,6 +35,9 @@
 PATH_USER = "/users"
 PATH_OAUTH_CLIENT = "/oauth-clients"
 
+# logger
+logger = logging.getLogger(__package__)
+
 
 # Engine sizes
 @unique
@@ -887,11 +891,13 @@ def exec(
     readonly: bool = True,
     **kwargs
 ) -> TransactionAsyncResponse:
+    logger.info('exec: database %s engine %s readonly %s' % (database, engine, readonly))
     start_time = time.time()
     txn = exec_async(ctx, database, engine, command, inputs=inputs, readonly=readonly)
     # in case of if short-path, return results directly, no need to poll for
     # state
     if not (txn.results is None):
+        logger.info('transaction id: %s' % txn.transaction["id"])
         return txn
 
     rsp = TransactionAsyncResponse()
@@ -903,6 +909,8 @@ def exec(
         start_time=start_time,
     )
 
+    logger.info('transaction id: %s' % txn["id"])
+
     rsp.transaction = get_transaction(ctx, txn["id"], **kwargs)
     rsp.metadata = get_transaction_metadata(ctx, txn["id"], **kwargs)
     rsp.problems = get_transaction_problems(ctx, txn["id"], **kwargs)

railib/rest.py

@@ -15,6 +15,7 @@
 """Low level HTTP interface to the RelationalAI REST API."""
 
 import json
+import logging
 from os import path
 from urllib.parse import urlencode, urlsplit, quote
 from urllib.request import Request, urlopen
@@ -38,6 +39,9 @@
 EXPIRES_IN_KEY = "expires_in"
 SCOPE = "scope"
 
+# logger
+logger = logging.getLogger(__package__)
+
 
 # Context contains the state required to make rAI REST API calls.
 class Context(object):
@@ -215,7 +219,14 @@ def request(ctx: Context, method: str, url: str, headers={}, data=None, **kwargs
     req = Request(method=method, url=url, headers=headers, data=data)
     req = _authenticate(ctx, req)
     _print_request(req)
-    return urlopen(req)
+    rsp = urlopen(req)
+
+    # logging
+    content_type = headers["Content-Type"] if "Content-Type" in headers else ""
+    agent = headers["User-Agent"] if "User-Agent" in headers else ""
+    request_id = rsp.headers["X-Request-ID"] if "X-Request-ID" in rsp.headers else ""
+    logger.debug(f"{rsp._method} HTTP/{rsp.version} {content_type} {rsp.url} {rsp.status} {agent} {request_id}")
+    return rsp
 
 
 def delete(ctx: Context, url: str, data, headers={}, **kwargs):

test/logger.config

@@ -0,0 +1,26 @@
+[loggers]
+keys=root,railib
+
+[handlers]
+keys=stream_handler
+
+[formatters]
+keys=fmt
+
+[logger_root]
+level=INFO
+handlers=stream_handler
+
+[logger_railib]
+level=DEBUG
+handlers=stream_handler
+qualname=railib
+
+[handler_stream_handler]
+class=StreamHandler
+level=DEBUG
+formatter=fmt
+args=(sys.stdout,)
+
+[formatter_fmt]
+format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

test/test_integration.py

@@ -4,6 +4,7 @@
 import uuid
 import tempfile
 
+from logging.config import fileConfig
 from pathlib import Path
 from railib import api, config
 
@@ -39,6 +40,9 @@
 engine = f"python-sdk-{suffix}"
 dbname = f"python-sdk-{suffix}"
 
+# init "rai" logger
+fileConfig("./test/logger.config")
+
 
 class TestTransactionAsync(unittest.TestCase):
     def setUp(self):