Using BugSnag As A Server-Side Logging Service In ColdFusion

BugSnagApiClient.cfc

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" ) );

	}

}

LoggerForBugSnag.cfc

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" );

	}

}

RequestMetadata.cfc

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()
		);

	}

}

test.cfm

<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>