Logging

In the last step, we set up our cache to store the results of a third-party call. But the end result is the same: how can we tell whether the cache or the external API was accessed, and debug that flow if needed?

Let’s add some logging to our form. The Caliper SDK is designed to support robust logging with no configuration or setup required. Logging will save a ton of headaches while developing your form, and even more once it is deployed.

Note

Logging is highly configurable, check out the complete Logging reference guide if you have something special in mind.

Writing to the logs is a simple one liner:

self.logger.info('This string will be logged')

Our logger supports four levels of logging, debug, info, warning and error. When you run your server with q2 run, you can provide a logging level, and only log lines of that level or higher will be printed to terminal.:

$ q2 run -l DEBUG

This will print all lines to the terminal. By default, q2 run prints only lines of INFO and above.

Let’s add some logging to our get_currency_rates method so we can easily see whether the cache was accessed, or whether the external API call was unsuccessful:

@cache(timeout=3600, key="quotes_dictionary")
async def get_currency_rates(self):
    self.logger.info('Getting current exchange rates from API')
    response = await q2_requests.get(
        self.logger,
        'https://local-dev-api.q2developer.com/projects/currencyRates',
        headers={
            'apikey': 'S6TczFkiWjDZy7FElvqKYMogzdcEcoQy'
        }
    )
    response_as_dict = response.json()
    quotes_dictionary = response_as_dict.get('quotes', {})
    if not quotes_dictionary:
        self.logger.error('CurrencyRates API request failed')

    return quotes_dictionary

This gives us some additional information, and provides some basic error handling if our API call should fail to return rates for any reason.

Simple, right? But wait, there’s more!

We have created a default_summary_log and override_summary_log property to help you. Notice, a summary log line containing your HQ_ID (and customer key if your extension is set to multitenant) appears in your terminal when you run your server. This comes from our default_summary_log property, which will log both keys when found by default. The override_summary_log property can be overriden to include additional information. For instance, maybe we want to log out our session and user information in addition to the HQ_ID and customer_key.

Why don’t we try this out?

@property
def override_summary_log(self):
    summary_dict = {
        'ABA': self.online_session.aba,
        'HQ_Auth_Token': self.online_session.hq_auth_token,
        'Session_ID': self.online_session.session_id,
        'FirstName': self.online_user.first_name,
        'LastName': self.online_user.last_name,
        'User_ID': self.online_user.user_id,
        }
    return summary_dict

Once you save your changes, the key value pairs above should appear in your ‘summary line’ log.

Note

The override_summary_log property looks for a couple of things: keys with spaces will be delimited with underscores and any apostrophes included will be removed.

This extension is looking good, but it’s completely static. We’ll go over methods for adding some configuration in the next step.