Debugging & Logging
Debugging in serverless environments can often be a complex chore which feels like working with a black box. Refinery attempts to greately simplify the debugging process through the use of its scalable logging system built on top of S3. The logging system in Refinery is configurable and allows for extreme verbosity when needed to help pinpoint and easily reproduce problems.
What Refinery Logs
Before we dive into debugging your service, we first have to talk about logging. Refinery logs a large amount of metadata about a
Code Block's given execution. For example, some of the data which is logged is the following:
- The full input to the
- The full returned output of the
stderroutputted during execution.
- Time of execution.
The reason for this level of verbosity is to allow easy reproduction of issues. Since development in Refinery is accomplished by building small functional blocks in a pipeline fashion, logging the full input and output allows developers to easy replay the same inputs into the same blocks in the IDE in order to replicate the issue.
Configuring Your Logging Level
Refinery allows for configuring different levels of logging for when your service is deployed in production. The levels of logging available are:
Log all executions: Every time a
Code Blockis executed a log file is written.
Log only errors: A log file is written only when a
Code Blockencounters an uncaught exception.
No logging: No logs are written under any circumstance.
The major tradeoff with logging all executions, error only logging, and no logging is cost. The
Code Blocks that Refinery deploys make use of S3 for storing of all of the created log objects. This means that you will incur the appropriate level of cost for each write you do to S3. As of the time of this writing, saving an object to S3 is billed at $0.005 per 1,000 requests. While this may seem inexpensive, it can add up if you're doing full verbosity logging on pipelines with a large number of executions. It's important to always be mindful about the amount of resources you're consuming when using Refinery.
In order to configure your logging level for a given project, navigate to the
Settings tab for your project. Change the drop-down selection for
Logging Level to change your logging level.
Changes in logging level currently require a re-deploy to take effect. Just changing the setting will not automatically change an existing deployment's logging settings.
Debugging a Deployment
To debug an existing deployment navigate to the
Deployment tab of your project. Once you've done so click on the
Block Executions button on the left side of the page.
Block Executions panel shows a list of executions which have occurred for this deployment. These executions are grouped into "execution pipelines", which means that you can follow a chain of executions from the start to the end of the chain. This allows you to follow the flow of execution in your deployed service and better understand the chain of events that led to a particular error or bug.
Once you select a given execution pipeline from the list you'll see that the
Code Blocks are marked as successful or unsuccessful . These indicate whether or not your
Code Block encountered an uncaught exception or if it executed successfully without issue.
For ongoing executions the
Code Blocks will automatically update as the execution continues. As can be seen in the above video the final code block in the execution pipeline automatically updates after its execution completes.
Investigate a Code Block Execution
To investigate a given
Code Block in an execution pipeline you can click on the relevant
Code Block (/) to see information about its execution. This information is displayed under the
Execution Details tab of the
Block Execution Logs pane.
The following information is provided about
Code Block execution:
Time: The time the
Status: This is the execution status of the selected
Code Block. For example, this would be
Successif the block executed successfully or
Uncaught Exceptionif an uncaught exception occurred.
Block Input Data: This is the data that was passed to the
Code Blockfrom a previous block. For example, if the previous
[1,2,3,4]and transitioned to the current block its Block Input Data would be
Execution Output: The execution output is all of the output your
Code Blockproduced during its execution. This includes statements intentionally printed or logged as well as full stack-traces when errors occur.
Return Data: The data returned from the selected
Code Block. If the currently-selected
Code Blockreturned the string
"example", this would be shown in the return data section.
Additionally you can view read-only information about the deployed
Code Block (such as the code contents) by selecting the
Selected Block tab.
Reproduce a Deployed Code Block Issue in the Editor
Refinery allows you to very easily reproduce errors encountered in deployed
Code Blocks due to the fact that it can log the full Block Input Data passed to the block at execution time. You can reproduce the bug and fix the problem by copying the
Block Input Data and pasting it into the
Block Input Data field when running the same block in the
Execution Pipeline Grouping
These execution pipelines are grouped by the initiating trigger that caused the pipeline to start executing. For example, if a deployed project had a
Timer Block connected to two
Code Blocks each attached Code Block would be grouped into it's own execution pipeline. However if a deployed project had a
Timer Block connected to a
Code Block which is connected to another
Code Block - they would all be grouped into the same execution pipeline.