Skip to main content
Ben Nadel at Scotch On The Rocks (SOTR) 2011 (Edinburgh) with: Gareth Sykes
Ben Nadel at Scotch On The Rocks (SOTR) 2011 (Edinburgh) with: Gareth Sykes ( @BoozyDoo )

Using BugSnag As A Server-Side Logging Service In ColdFusion

By on
Tags:

I've been on the lookout for a better error logging service; and, over on Facebook, Jay Bronson recommended that I look at BugSnag. They have a free-tier, so I signed up to try it out. And, I must say, I'm very pleased with the User Interface (UI) and the basic functionality. That said, I could not get the Java SDK (Software Development Kit) working with JavaLoader. As such, I hacked together some ColdFusion code that would do just enough to send data to the BugSnag API. What I have is far from feature complete; but, I thought it might be worth sharing.

My ColdFusion code is broken up into two parts:

  • An HTTP client for the BugSnag API.

  • A Logger that translates / marshals logging requests into BugSnag API calls (using the above HTTP client).

It's not always easy to figure out what functionality should go in which component. It would be easy to jam a lot of "stuff" into the BugSnag HTTP client. But, so much of that logic would be "application specific". And, while I'm not building something that I intend to share, it's always nice to have good boundaries in my code. It keeps the code clean and easy to maintain.

To that end, my BugSnag HTTP client is just a thin wrapper around the CFHttp tag. It exposes a single method, notify(), which sends an array of "events" to the BugSnag API.

The data posted to the notify end-point is rather complex. And, in a perfect world, this ColdFusion component would do some validation around the data structure. However, since I'm just trying to get something working, this HTTP client is going to do nothing more than blindly pass-through the event structure that it has been provided.

component
	output = false
	hint = "I report server-side errors to the BugSnag API."
	{

	/**
	* I initialize the BugSnag API client.
	*/
	public void function init( required string apiKey ) {

		variables.apiKey = arguments.apiKey;
		variables.payloadVersion = 5;
		variables.notifier = {
			name: "BugSnag ColdFusion (Custom)",
			version: "0.0.1",
			url: "https://www.bennadel.com/"
		};

	}

	// ---
	// PUBLIC METHODS.
	// ---

	/**
	* I notify the BugSnag API about the given events.
	*/
	public void function notify(
		required array events,
		numeric timeoutInSeconds = 5
		) {

		cfhttp(
			result = "local.apiResponse",
			method = "post",
			url = "https://notify.bugsnag.com/",
			getAsBinary = "yes",
			timeout = timeoutInSeconds
			) {

			cfhttpParam(
				type = "header",
				name = "Bugsnag-Api-Key",
				value = apiKey
			);
			cfhttpParam(
				type = "header",
				name = "Bugsnag-Payload-Version",
				value = payloadVersion
			);
			cfhttpParam(
				type = "header",
				name = "Bugsnag-Sent-At",
				value = dateTimeFormat( now(), "iso" )
			);
			cfhttpParam(
				type = "header",
				name = "Content-Type",
				value = "application/json"
			);
			cfhttpParam(
				type = "body",
				value = serializeJson({
					apiKey: apiKey,
					payloadVersion: payloadVersion,
					notifier: notifier,
					events: events
				})
			);
		}

		if ( isFailureResponse( apiResponse ) ) {

			// Even though we are asking the request to return a Binary value, the type
			// is only guaranteed if the request comes back properly. If something goes
			// terribly wrong (such as a "Connection Failure"), the fileContent will still
			// be returned as a simple string.
			var fileContent = isBinary( apiResponse.fileContent )
				? charsetEncode( apiResponse.fileContent, "utf-8" )
				: apiResponse.fileContent
			;

			throw(
				type = "BugSnagApiClient.ApiFailure",
				message = "BugSnag notify API failure.",
				detail = "Returned with status code: #apiResponse.statusCode#",
				extendedInfo = fileContent
			);

		}

	}

	// ---
	// PRIVATE METHODS.
	// ---

	/**
	* I determine if the given API response has a failure / non-2xx status code.
	*/
	private boolean function isFailureResponse( required struct apiResponse ) {

		return( ! apiResponse.statusCode.reFind( "2\d\d" ) );

	}

}

As you can see, my BugSnag HTTP Client isn't doing much - it's just creating a simple interface for the underlying HTTP request. All of the real work happens in another ColdFusion component, LoggerForBugSnag.cfc. This component exposes two different types of methods: several for logging arbitrary data; and, a single one for logging exceptions:

  • critical( message [, data ] )
  • debug( message [, data ] )
  • error( message [, data ] )
  • info( message [, data ] )
  • warning( message [, data ] )
  • logException( error [, message [, data ]] )

Now, BugSnag isn't really designed to accept "arbitrary data" - it's a bug tracking system, not a log aggregator. But, I'm intending to use BugSnag for both. Which means, I have to shoehorn arbitrary data into an "exception" model.

This turns out not to be all that complicated. Essentially, I'm just taking my arbitrary, non-exception log messages and log levels and I'm using them to define a faux "Exception":

  • errorClass => custom message
  • message => custom level (ex, info)

Ideally, the "custom message" would become the exception message; but, for purely superficial reasons, I prefer the BugSnag UI grouping when I use my custom messages as the "error type".

Part of this shoehorning also involves a Stacktrace. Out of the box, ColdFusion errors come with a captured stacktrace. However, when I'm logging arbitrary messages, there's no such data. To bridge that gap, I'm using the callStackGet() function to generate a stacktrace.

With all that said, here's my LoggerForBugSnag.cfc ColdFusion component. Like I said above, I'm not building this to be reusable; so, there is stuff here that is tightly coupled to the way my ColdFusion application is architected. I'm just sharing this a general curiosity.

component
	accessors = true
	output = false
	hint = "I provide logging methods for errors and arbitrary data."
	{

	// Define properties for dependency-injection.
	property bugSnagApiClient;
	property config;
	property requestMetadata;

	// ---
	// PUBLIC METHODS.
	// ---

	/**
	* I report the given item using a CRITICAL log-level.
	*/
	public void function critical(
		required string message,
		any data = {}
		) {

		logData( "Critical", message, data );

	}


	/**
	* I report the given item using a DEBUG log-level.
	*/
	public void function debug(
		required string message,
		any data = {}
		) {

		logData( "Debug", message, data );

	}


	/**
	* I report the given item using an ERROR log-level.
	*/
	public void function error(
		required string message,
		any data = {}
		) {

		logData( "Error", message, data );

	}


	/**
	* I report the given item using an INFO log-level.
	*/
	public void function info(
		required string message,
		any data = {}
		) {

		logData( "Info", message, data );

	}


	/**
	* I log the given data as a pseudo-exception (ie, we're shoehorning general log data
	* into a bug log tracking system).
	*/
	public void function logData(
		required string level,
		required string message,
		required any data = {}
		) {

		// NOTE: Normally, the errorClass represents an "error type". However, in this
		// case, since we don't have an error to log, we're going to use the message as
		// the grouping value. This makes sense since these are developer-provided
		// messages and will likely be unique in nature.
		sendToBugSnag({
			exceptions: [
				{
					errorClass: message,
					message: "#level# log entry",
					stacktrace: buildStacktraceForNonError(),
					type: "coldfusion"
				}
			],
			request: buildRequest(),
			context: buildContext(),
			severity: buildSeverity( level ),
			app: buildApp(),
			metaData: buildMetaData( data )
		});

	}


	/**
	* I report the given EXCEPTION object using an ERROR log-level.
	*/
	public void function logException(
		required any error,
		string message = "",
		any data = {}
		) {

		// Adobe ColdFusion doesn't treat the error like a Struct (when validating call
		// signatures). Let's make a shallow copy of the error so that we can use proper
		// typing in subsequent method calls.
		error = structCopy( error );

		switch ( error.type ) {
			// The following errors are high-volume and don't represent much value. Let's
			// ignore these for now (since they aren't something that I can act upon).
			case "BenNadel.Partial.Go.NotFound":
			case "BenNadel.Partial.BlogPost.NotFound":
			case "Nope":
				// Swallow error for now.
			break;
			default:
				sendToBugSnag({
					exceptions: [
						{
							errorClass: error.type,
							message: buildExceptionMessage( message, error ),
							stacktrace: buildStacktrace( error ),
							type: "coldfusion"
						}
					],
					request: buildRequest(),
					context: buildContext(),
					severity: buildSeverity( "error" ),
					app: buildApp(),
					metaData: buildMetaData( data, error )
				});
			break;
		}

	}


	/**
	* I report the given item using a WARNING log-level.
	*/
	public void function warning(
		required string message,
		any data = {}
		) {

		logData( "Warning", message, data );

	}

	// ---
	// PRIVATE METHODS.
	// ---

	/**
	* I build the event app data.
	*/
	private struct function buildApp() {

		return({
			releaseStage: config.bugsnag.server.releaseStage
		});

	}


	/**
	* I build the event context data.
	*/
	private string function buildContext() {

		return( requestMetadata.getEvent().toList( "." ) );

	}


	/**
	* I build the log message for the given exception.
	*/
	private string function buildExceptionMessage(
		required string message,
		required struct error
		) {

		if ( message.len() ) {

			return( message );

		} else {

			return( error.message );

		}

	}


	/**
	* I build the event meta-data.
	*/
	private struct function buildMetaData(
		any data = {},
		struct error = {}
		) {

		return({
			urlScope: url,
			formScope: form,
			data: data,
			error: error
		});

	}


	/**
	* I build the event request data.
	*/
	private struct function buildRequest() {

		return({
			clientIp: requestMetadata.getIpAddress(),
			headers: requestMetadata.getHeaders(
				exclude = [ "cookie" ]
			),
			httpMethod: requestMetadata.getMethod(),
			url: requestMetadata.getUrl(),
			referer: requestMetadata.getReferer()
		});

	}


	/**
	* I build the event severity data.
	* 
	* NOTE: On the BugSnag side, the "level" information is a limited enum. As such, we
	* have to shoe-horn some of our internal level-usage into their finite set.
	*/
	private string function buildSeverity( required string level ) {

		switch ( level ) {
			case "fatal":
			case "critical":
			case "error":
				return( "error" );
			break;
			case "warning":
				return( "warning" );
			break;
			default:
				return( "info" );
			break;
		}

	}


	/**
	* I build the stacktrace for the given error.
	*/
	private array function buildStacktrace( required struct error ) {

		var tagContext = ( error.tagContext ?: [] );
		var stacktrace = tagContext
			.filter(
				( item ) => {

					return( item.template.reFindNoCase( "\.(cfm|cfc)$" ) );

				}
			)
			.map(
				( item ) => {

					return({
						file: item.template,
						lineNumber: item.line
					});

				}
			)
		;

		return( stacktrace );

	}


	/**
	* I build the stacktrace to be used for non-exception logging.
	*/
	private array function buildStacktraceForNonError() {

		var stacktrace = callstackGet()
			.filter(
				( item ) => {

					return( ! item.template.findNoCase( "LoggerForBugSnag" ) );

				}
			)
			.map(
				( item ) => {

					return({
						file: item.template,
						lineNumber: item.lineNumber
					});

				}
			)
		;

		return( stacktrace );

	}


	/**
	* I notify the BugSnag API about the given event using an async thread. Any errors
	* caught within the thread will be written to the error log.
	*/
	private void function sendToBugSnag( required struct notifyEvent ) {

		if ( ! config.isLive ) {

			sendToConsole( notifyEvent );

		}

		thread
			name = "loggerForBugSnag.sendToBugSnag.#createUuid()#"
			notifyEvent = notifyEvent
			{

			try {

				bugSnagApiClient.notify([ notifyEvent ]);

			} catch ( any error ) {

				writeLog(
					type = "error",
					log = "Application",
					text = "[#error.type#]: #error.message#"
				);

				if ( ! config.isLive ) {

					sendToConsole( error );

				}

			}

		}

	}


	/**
	* I write the given data to the standard output.
	*/
	private void function sendToConsole( required any data ) {

		cfdump( var = data, output = "console" );

	}

}

Now, to see this in action, let's try logging some arbitrary data:

<cfscript>

	// Override the context event data.
	request.event = [ "scribble", "bugsnag", "test" ];

	// Override the URL scope to make it more interesting.
	url.too = "legit";
	url.to = "quit";

	// Override the FORM scope to make it more interesting.
	form.foo = "bar";

	application.logger.info(
		"Demo logging for blog post",
		{
			hello: "world"
		}
	);

</cfscript>

After we run this CFML, if we look in the BugSnag dashboard, we see:

That's a really nice looking user interface. And, I love the fact that I can just include arbitrary data in my API call and BugSnag will add extra tabs to the UI to show that data (urlScope and formScope in this case). And, again, this isn't necessarily the best approach to use BugSnag or creating a clean abstraction - this is just what I am doing to get it working on my ColdFusion blog.

Epilogue on Gather Request Metadata

My ColdFusion logger above uses another ColdFusion component, RequestMetadata.cfc, to help build up the event payload. This is a component that I use to make it a bit easier to access parts of the inbound HTTP request object. For completeness, I'll share it here:

component
	output = false
	hint = "I provide utility methods for accessing metadata about the current request."
	{

	/**
	* I return the request event parts.
	*/
	public array function getEvent() {

		return( request.event ?: [] );

	}


	/**
	* I get the HTTP headers.
	*/
	public struct function getHeaders( array exclude = [] ) {

		var headers = getHttpRequestData( false )
			.headers
			.copy()
		;

		for ( var key in exclude ) {

			headers.delete( key );

		}

		return( headers );

	}


	/**
	* I get the HTTP host.
	*/
	public string function getHost() {

		return( cgi.server_name );

	}


	/**
	* I return the most trusted IP address reported for the current request.
	*/
	public string function getIpAddress() {

		var headers = getHeaders();

		// Try to get the IP address being injected by Cloudflare. This is the most
		// "trusted" value since it's not being provided by the user.
		if ( isHeaderPopulated( headers, "CF-Connecting-IP" ) ) {

			var ipValue = headers[ "CF-Connecting-IP" ].trim().lcase();

		// Fallback to any proxy IP. This is a user-provided value and should be used
		// with caution.
		} else if ( isHeaderPopulated( headers, "X-Forwarded-For" ) ) {

			var ipValue = headers[ "X-Forwarded-For" ].listFirst().trim().lcase();

		// If not, defer to the standard CGI variable.
		} else {

			var ipValue = cgi.remote_addr.trim().lcase();

		}

		// Check to make sure the IP address only has valid characters. Since this is
		// user-provided data (for all intents and purposes), we should validate it.
		if ( ipValue.reFind( "[^0-9a-f.:]" ) ) {

			throw(
				type = "InvalidIpAddressFormat",
				message = "The reported IP address is invalid.",
				detail = "IP address: #ipValue#"
			);

		}

		return( ipValue );

	}


	/**
	* I get the HTTP method.
	*/
	public string function getMethod() {

		return( cgi.request_method.ucase() );

	}


	/**
	* I return the HTTP protocol.
	*/
	public string function getProtocol() {

		return( ( cgi.https == "on" ) ? "https" : "http" );

	}


	/**
	* I return the HTTP referer.
	*/
	public string function getReferer() {

		return( cgi.http_referer );

	}


	/**
	* I return the HTTP scheme.
	*/
	public string function getScheme() {

		return( getProtocol() & "://" );

	}


	/**
	* I get the executed script.
	*/
	public string function getScriptName() {

		if ( cgi.path_info.len() ) {

			return( cgi.path_info );

		} else {

			return( cgi.script_name );

		}

	}


	/**
	* I return the HTTP URL.
	*/
	public string function getUrl() {

		var resource = ( getScheme() & getHost() & getScriptName() );

		if ( cgi.query_string.len() ) {

			return( resource & "?" & cgi.query_string )

		}

		return( resource );

	}


	/**
	* I return the client's user-agent.
	*/
	public string function getUserAgent() {

		return( cgi.http_user_agent );

	}

	// ---
	// PRIVATE METHODS.
	// ---

	/**
	* I determine if the given header value is populated with a non-empty, simple value.
	*/
	private boolean function isHeaderPopulated(
		required struct headers,
		required string key
		) {

		return(
			headers.keyExists( key ) &&
			isSimpleValue( headers[ key ] ) &&
			headers[ key ].trim().len()
		);

	}

}

Want to use code from this post? Check out the license.

Reader Comments

Post A Comment — I'd Love To Hear From You!

Post a Comment

I believe in love. I believe in compassion. I believe in human rights. I believe that we can afford to give more of these gifts to the world around us because it costs us nothing to be decent and kind and understanding. And, I want you to know that when you land on this site, you are accepted for who you are, no matter how you identify, what truths you live, or whatever kind of goofy shit makes you feel alive! Rock on with your bad self!
Ben Nadel