Introspecting Your Integrations with Prismatic's Built-in Logging

I've written in previous posts about the tenets of building proper twelve-factor apps. One of the twelve factors, logs, highlights the importance of having good logging in production. Proper logging gives you visibility into running applications, and allows you to spot trends, go back in time to find information about past events, and even automatically alert your incident management teams when logs indicate production issues.

In the integration world, it's important to know when an integration ran, how long its steps took, and if an integration fails to run it's important to be able to quickly identify what happened. An integration failing to run may not be your fault – maybe a third-party vendor's API was unavailable for a period of time – but it's important that you're able to identify and communicate correct information about integration outages to your customers and resolve issues quickly.

Good logging is important, but it isn't a wheel that you need to reinvent again and again, wasting time worrying about routing or storage of logs with every integration that you write. Prismatic comes with built-in, indexed, searchable logging functionality that can be configured to trigger alerts. It empowers all of your teams – dev, DevOps, support, and so on – with the information they need about what's going on with your customers' integrations. If you'd like, you can even give your customers access to logs so they can identify and debug issues with third-party vendors.

In this post, I'd like to look at Prismatic's built-in logging functionality. We'll check out how your incident management and support teams can search and filter instance logs so you can quickly diagnose and solve problems as they arise. We'll also look at how to configure alerting based on logs, so your teams can stay informed if an instance starts spitting warns or errors. Finally, we'll look at logging and error handling within custom components, so you can customize logs to be as useful as possible for you.

What does Prismatic log?

Prismatic automatically logs the start and end time of every instance that runs, as well as the start and end time of each action within each instance. If an instance begins to run slowly, these logs can help you diagnose which steps of the integration are taking a long time to run.

Default logs look like this, with lots of "starting instance foo" and "ending action bar" lines:

If an action in an instance throws an exception, the instance stops running and the error that is thrown is automatically logged. We can click on the error log line to see full details about the error that caused our instance to break. This can greatly expedite debugging production issues:

Searching and filtering instance Logs

Within Prismatic's log viewer, we can filter logs from all of our customers' instances by integration, date/time range, and log level. For example, if we want to diagnose why one integration was failing to run for multiple customers at a particular time, we can search for error log lines for a specific integration that occurred in a particular interval of time:

We can also view logs for a specific customer, or for a specific instance of an integration by opening the Logs tab within the customer or instance screens respectively. This is handy if we're trying to debug an instance- or customer-specific issue.

Within any of the log viewers (all-customer, instance-specific, or customer-specific screens), we can search for specific keywords using the search bar on the top of the page. Here, we're grabbing all lines related to aws:

In addition to viewing logs in the browser, you can pull logs programmatically for an instance through Prismatic's GraphQL API – check out our relevant API docs.

Alerting based on logged lines

If instances that we've deployed generate error or warning log lines, something is likely going wrong with those instances and our team should be alerted. We can configure an alert monitor to trigger when logs meet or exceed a particular log level:

If our alert monitor fires, we our team members will receive emails or SMS texts with a link to the log lines that caused the trigger to fire. That way, we can respond to production issues in a timely manor.

To learn more about monitoring and alerting in Prismatic, check out this post.

Logging from a custom component

In addition to the things that Prismatic logs already (start and end times of instance runs and their actions), we can write our custom components to log additional useful information about the inputs that the component received. Let's look back at an example custom component, which converts pounds of rocket fuel to gallons and vice-versa. I'd like to add some log lines to our component so we can better introspect what our component does when it's invoked. Specifically, let's add logging to accomplish three different things:

1. Log the type and amount of fuel that is passed to our custom component.
2. Throw an error with an appropriate error message if the custom component receives a fuel type that it doesn't know how to convert.
3. Log a warning, but proceed as normal if the fuel input amount is a negative number. A negative number of gallons of fuel obviously doesn't make sense for most integrations, though I could see a company possibly being indebted to another, so we'll just log a warning in the event of negative fuel amounts and move on.

To log these lines, we'll use the logger object that is passed into a component action's perform function. Every custom component is passed a logging object to make log lines look nice; that logger is part of the context parameter that is passed into the perform function.

First, let's start by logging the type and amount of fuel that's passed into our component:

perform: async ({ logger }, { fuelType, fuelAmount }) => {
  logger.info(`Converting ${fuelAmount} pounds of ${fuelType} to gallons.`)

Next, let's throw an error if our component cannot handle the type of fuel that was passed to it:

if (!(fuelType in gallonsToPoundsConversion)) {
  throw Error(`${fuelType} is not a valid fuel type.`);
}

Finally, we'll log a warning (but not throw an error) if the amount of fuel our component received was negative:

if (Number(fuelAmount) < 0) {
  logger.warn(`Received a negative amount of fuel. That is likely incorrect.`);
}

After adding those three lines and publishing our modified custom component, I created an integration that tests the code paths above. This test integration first passes in reasonable data to our custom component, then pass in a negative value for fuel amount, and then passes in an unknown fuel type. Logs for our integration now look like this:

We can see that our inputs are logged out properly for each of the three steps, our custom component logged a warn when the amount of fuel was negative, and it threw an error when it was presented with an unknown fuel type. The warn log line is indicated by a yellow dot, and the error that was thrown is indicated by a red dot above.

With just a few lines of code, our custom component is now more easy to debug if and when issues arise, and we can now be alerted on if it receives unexpected data (negative fuel amounts or unknown fuel types) as input.

Logging from the code component

Since we talked about logging in custom components, I should mention that logging in a code component works exactly the same way. You can snag the logger object from parameters passed in to the code component, and invoke logger.{debug,info,warn,error}() to write log lines to Prismatic's log service:

The above output was generated by a code component that read:

module.exports = async ({ logger, configVars, credential }, params) => {
  logger.debug("This is a debug line");
  logger.info("This is an info line");
  logger.warn("This is a warn line");
  logger.error("This is an error line");
};

Once again, error log lines show up in red, warn in yellow, and info and debug lines in blue.

Additional reading

Additional information about Prismatic's built-in logger can be found in our docs. For more information on writing custom components, check out the logging portion of this article. Feel free to reach out if you'd ever like to chat about B2B software development and customer integrations. We'd love to talk about integration issues you're facing, and how we can help solve them.