So you've got a misbehaving Netlify function and you need to debug it. How can you get more logging? It would be great if we could add log lines to our function, but only output them when we need them so we don't create a bunch of noise & expense. We can do this with Prefab dynamic logging for Netlify.
In this post, we'll add dynamic logging to our Netlify function that will let us turn on debug logging for:
- A single function
- A particular user
- For just 1 hour
The Code We Want To Debug
Here's a really basic skeleton of a Netlify function. It's a simple function that takes a user id from the url and returns some data from the database. Let's pretend it's misbehaving and we need to debug it.
We've added two console.log statements, but this probably isn't shippable as is because, at high throughput, we're going to print out way too much logging.
export default async (req, context) => {
const {userId} = context.params;
var sql = "SELECT * FROM table WHERE user_id = $1";
console.log(`running the following SQL ${sql}`, {userId: userId});
db.run(sql, [userId], function (err, rows) {
console.log("query returned", {rows: rows});
return new Response("200 Okey-dokey");
});
};
export const config = {
path: "/users/:userId"
};
Add & Initialize Prefab
The first thing we're going to do is add Prefab. We'll use the standard NodeJS server-side client, but we'll turn off the background processes. Since we're running on a lambda, we don't want any background processes in our function.
import {Prefab} from "@prefab-cloud/prefab-cloud-node";
var prefab = new Prefab({
apiKey: process.env.PREFAB_API_KEY,
enableSSE: false, // we don't want any background process in our function
enablePolling: false, // we'll handle updates ourselves
defaultLogLevel: "warn",
collectLoggerCounts: false, // turn off background telemetry
contextUploadMode: "none", // turn off background telemetry
collectEvaluationSummaries: false, // turn off background telemetry
});
await prefab.init();
Swap Logging to Prefab
Rather than use a console.log, we will create a Prefab logger with the name netlify.functions.hello and the default level of warn so we don't get too much output.
We can replace our console.log with some logger.debug and logger.info, and now it's safe to deploy. They won't emit logs until we turn them on.
const logger = prefab.logger("netlify.functions.hello", "warn");
// simple info logging
logger.info(`getting results for ${userId}`);
var sql = "SELECT * FROM table WHERE user_id = $1";
// more detailed debug logging
logger.debug(`running the following SQL ${sql} for ${userId}`);
db.run(sql, [userId], function (err, rows) {
logger.debug("query returned", {rows: rows});
return new Response("200 Okey-dokey");
});
This logging will not show up in your Netlify logs yet, because the logger is warn but the logging here is info and debug. That means it's safe to go ahead and deploy.
Listen for changes and Turn On Debugging in the UI
Since we turned off the background polling, we'll want to update prefab in line. We can do this by calling the updateIfStalerThan with our desired polling frequency. This is a quick check to a CDN, taking around 40ms (once every minute).
prefab.updateIfStalerThan(60 * 1000); // check for new updates every minute
We can now toggle logging in the Prefab UI! Just choose the function, change it to debug, and a minute later, you'll see the debug output in your logs.
This is pretty cool and you can stop here if this solves your needs. With this pattern you'll be able to instantly turn logging on and off for any function in your app.
Adding Per User Targeting
Now we'll go deeper and add per user targeting. This will let us laser focus in on a particular problem.
To add per user targeting, we need to tell Prefab who the current user is. We do this by setting some context for Prefab so it can evaluate the rules. We should also move the logger creation inside this context so that the logger has this context available to it.
// take the context from our url /users/123 and give it to prefab as context
const {userId} = context.params;
const prefabContext = {user: {key: userId}};
// wrap our code in this context
prefab.inContext(prefabContext, (prefab) => {
// logger goes inside the context block
const logger = prefab.logger("netlify.functions.hello", "warn");
logger.info(`getting results for ${userId}`);
var sql = "SELECT * FROM table WHERE user_id = $1";
logger.debug(`running the following SQL ${sql} for ${userId}`);
db.run(sql, [userId], function (err, rows) {
logger.debug("query returned", {rows: rows});
return new Response("200 Okey-dokey");
});
});
We can now create the rules in the Prefab UI for just 1 hour and just user 1234. This will let us see the debug output for just that user and automatically stop debug logging after the hour is up.
That's It!
If we load the pages /users/1000, /users/1001, and /users/1234, we'll see the following output in our logs. We have INFO level logging for the first two, but DEBUG level logging for the last one because it matches our user.key rule.
INFO netlify.functions.hello: getting results for 1000
INFO netlify.functions.hello: getting results for 1001
INFO netlify.functions.hello: getting results for 1234
DEBUG netlify.functions.hello: running the following SQL SELECT * FROM table WHERE user_id = $1 for 1234
DEBUG netlify.functions.hello: query returned { rows: [ { id: 1, user_id: 1234, account: active, balance: 340 } ] }
Full Code Example
import {Prefab} from "@prefab-cloud/prefab-cloud-node";
var prefab = new Prefab({
apiKey: process.env.PREFAB_API_KEY,
enableSSE: false, // we don't want any background process in our function
enablePolling: false, // we don't want any background process in our function
defaultLogLevel: "warn",
collectLoggerCounts: false, // we don't want any background process in our function
contextUploadMode: "none", // we don't want any background process in our function
collectEvaluationSummaries: false, // we don't want any background process in our function
});
export default async (req, context) => {
prefab.updateIfStalerThanSec(60 * 1000); // check for new updates every minute
// take the context from our url /users/123 and give it to prefab as context
const {userId} = context.params;
const prefabContext = {user: {key: userId}};
prefab.inContext(prefabContext, (prefab) => {
const logger = prefab.logger("netlify.functions.hello", "warn");
logger.info(`getting results for ${userId}`);
var sql = "SELECT * FROM table WHERE user_id = $1";
logger.debug(`running the following SQL ${sql} for ${userId}`);
db.run(sql, [userId], function (err, rows) {
logger.debug("query returned", {rows: rows});
return new Response("200 Okey-dokey");
});
});
};
export const config = {
path: "/users/:userId"
};
To learn more about Prefab dynamic logging, check out the dynamic logging or check out the other things you can do with Prefab in Netlify like feature flags.
We set this up to target a particular user, but you can easily target anything else you provide in the context. Team ID, transaction ID, device ID, device type are all common examples.
Happy dynamic logging!