Watching server logs for errors is a cumbersome way to find problems in server code.
Back when I was actively doing Ruby on Rails for personal development, I used the "exceptional" gem which would report exceptions to a now defunct online service (exceptional.io) to monitor any errors that occurred in your application. It was a nice tool, but it had 2 drawbacks for me.
- It was just for Ruby on Rails
- It required a 3rd party site to store the exception data.
At the time, I was working at IBM so I needed a tool that worked for Java applications, and they didn't look kindly on potentially confidential information being stored outside of the IBM network, so I created my own version of Exception that I named IBMExceptional (you can read a little bit about it and see some screenshots on my IBM portfolio page). The site for monitoring the errors was a Rails application, but I created a Java client for it that provided 2 reporting options.
First, I provided an IBMExceptional exception class that could be extended for application specific exceptions.
class MyProjectException extends IBMExceptional {
@SuppressWarnings("unused")
public MyProjectException() {
super();
}
public MyProjectException(String message, Throwable cause) {
super(message, cause);
}
public MyProjectException(String message) {
super(message);
}
@SuppressWarnings("unused")
public MyProjectException(Throwable cause) {
super(cause);
}
}
This base exception class would report any instances of thrown exceptions to IBMExceptional.
try {
throw new MyProjectException("This is a test exception.");
} catch (MyProjectException e) {
// Handle exception as desired, but it was reported to IBM Exceptional
}
The advantage of this option is that the exception reporting is transparent and automatic. The disadvantage is that only exceptions that are subclassed from the IBMExceptional base class will be reported.
Second, I provided a log appender, IBMExceptionalAppender, so that any logged errors would be reported to IBMExceptional. You added a few configuration lines to log4j.properties like
log4j.rootCategory=info, exceptional
log4j.appender.exceptional=com.ibm.IBMExceptionalAppender
Then calls to the logger with an exception would be reported to IBMExceptional.
try {
throw new NullPointerException("Fake Null pointer");
} catch (NullPointerException e) {
logger.error("Error description", e);
}
The advantage of this option is that all exception types can be reported. The disadvantage is that it requires that the exceptions are logged by the programmer.
This worked well and was all well and good while I remained at IBM, but I have since moved on. For my current job at USIC, I've led the development of a Java API server using Spring Boot (feeding Angular UIs) and a C# .NET (Framework) application and decided I would similarly like to easily monitor when errors occur on the servers, but this time, instead of having some web site to monitor the errors, I thought it would be much simpler and be sufficient to just send them to dedicated Slack channels.
For Java we went the route of a log appender, for .NET we could tie into the System.Web.HttpApplication Application_Error handler.
Java Spring Boot application with log appender
Spring Boot uses logback rather than log4j, so in logback-spring.xml we defined a new appender for errors.
<appender name="SLACK" class="com.usicllc.jsonapi.log.SlackAppender">
<profile>${profile}</profile>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
</appender>
Then the SlackAppender class utilizes the JSlack library and looks like:
public class SlackAppender extends AppenderBase<ILoggingEvent> {
@Override
protected void append(ILoggingEvent event) {
String errorMessage = event.getFormattedMessage();
StringBuffer message = new StringBuffer("*Error: " + errorMessage + "*\n\n");
String att = null;
Map<String, String> mdcMap = event.getMDCPropertyMap();
if (mdcMap != null) {
String reqUrl = mdcMap.get("REQUEST_URL");
String reqMethod = mdcMap.get("REQUEST_METHOD");
String reqQueryString = mdcMap.get("REQUEST_QUERY_STRING");
String reqUserAgent = mdcMap.get("REQUEST_USER_AGENT");
String reqRealIp = mdcMap.get("REQUEST_X_REAL_IP");
String reqUser = mdcMap.get("REQUEST_USER");
String reqBody = mdcMap.get("REQUEST_BODY");
if (reqMethod != null) {
message.append("*REQUEST_METHOD:* " + reqMethod + "\n");
message.append("*REQUEST_URL:* " + reqUrl + "\n");
if (reqQueryString != null) {
try {
message.append("*REQUEST_QUERY_STRING:* " + URLDecoder.decode(reqQueryString, "UTF-8") + "\n");
} catch (UnsupportedEncodingException e) {
}
}
if (reqBody != null) {
message.append("*REQUEST_BODY:* " + reqBody + "\n");
}
message.append("*REQUEST_USER_AGENT:* " + reqUserAgent + "\n");
message.append("*REQUEST_X_REAL_IP:* " + reqRealIp + "\n");
message.append("*REQUEST_USER:* " + reqUser + "\n");
}
}
// If we have an exception being reported, then add it to the message
//
if (event.getThrowableProxy() != null) {
StackTraceElementProxy[] stArray = event.getThrowableProxy().getStackTraceElementProxyArray();
if (stArray.length > 0) {
// first 10 lines of the stack trace are added to the messages as a code block
// Full stack trace is also added as an attachment
message.append("*Stack Trace:*\n```");
String exceptionMessage = event.getThrowableProxy().getMessage();
StringBuffer stackTrace = new StringBuffer("*Error Message: " + exceptionMessage + "*\n");
for (int i = 0; i < stArray.length; i++) {
StackTraceElement t = stArray[i].getStackTraceElement();
String traceLine = t.toString();
if (i < 10) {
// 1st 10 lines are added to the main message in a code block
message.append(traceLine + "\n");
}
if (traceLine.startsWith("com.usicllc.jsonapi")) {
// emphasize where the error was in our code
stackTrace.append("*" + traceLine + "*\n");
} else {
stackTrace.append(traceLine + "\n");
}
}
if (stArray.length > 10) {
message.append("...\n");
// Full stack trace is more than the 10 lines shown (usually the case)
// Add the full stacktrace as an attachment
Attachment attachment = Attachment.builder()
.title("Full Stack Trace")
.text(stackTrace.toString())
.build();
att = "[{\"title\" :\""+attachment.getTitle()+":\n"+"\",\"text\": \""+attachment.getText().replace("\\", "\\\\")+"\"}]";
}
message.append("```");
}
}
String payload = "{\"channel\": \"" + this.getSlackChannel()
+ "\",\"username\": \"jsonapi\",\"text\": \""
+ message.toString().replace("\\", "\\\\")
+ "\",\"attachments\":" + att + "}";
WebhookResponse webhookResponse;
try {
webhookResponse = Slack.getInstance().send(
this.getSlackUrl(), payload);
if (webhookResponse.getCode() != 200) {
logger.debug("Unable to send Slack Exception - http error:" + webhookResponse.toString());
}
} catch (IOException e) {
e.printStackTrace();
}
}
}
The stack trace is added both with the first 10 lines in a code block in the message body and then the full stack trace as an attachment because its more readable as a code block due to no line wrapping and the use of a monospaced font, but Slack will limit the message size and most stack traces will exceed the limit so adding the full stack trace an attachment provides access to everything albeit in a less readable format.
Now, it could have just logged the exception message and stack trace, but it's certainly more helpful to know what request caused the problem and that's where we took advantage of the logback MDC (Mapped Diagnoatic Context) to retrieve request data in a Spring GenericFilterBean named PreRequestProcessingFilter Spring will inject this into the request filter chain and the filter code looks like:
@Component
public class PreRequestProcessingFilter extends GenericFilterBean implements CurrentUser {
Logger logger = LoggerFactory.getLogger(PreRequestProcessingFilter.class);
@SuppressWarnings("unchecked")
@Override
public void doFilter(ServletRequest req, ServletResponse res, FilterChain filterChain) {
try {
String bodyJson = null;
RequestWrapper wrapper = null;
String method = ((HttpServletRequest) req).getMethod();
String contentType = ((HttpServletRequest) req).getContentType();
// Get a copy of the request body for JSON POST and PATCH requests
if (contentType != null &&
(contentType.startsWith("application/json") || contentType.startsWith("application/vnd.api+json")) &&
(method.equalsIgnoreCase("POST") || method.equalsIgnoreCase("PATCH"))) {
wrapper = new RequestWrapper((HttpServletRequest) req);
byte[] body = StreamUtils.copyToByteArray(wrapper.getInputStream());
Map<String, Object> jsonRequest = new ObjectMapper().readValue(body, Map.class);
bodyJson = jsonRequest.toString();
}
String user = getUserName();
StringBuffer requestURL = ((HttpServletRequest) req).getRequestURL();
if (requestURL != null) {
MDC.put("REQUEST_URL", requestURL.toString());
}
MDC.put("REQUEST_METHOD", method);
MDC.put("REQUEST_QUERY_STRING", ((HttpServletRequest) req).getQueryString());
MDC.put("REQUEST_USER_AGENT", ((HttpServletRequest) req).getHeader("User-Agent"));
MDC.put("REQUEST_X_REAL_IP", ((HttpServletRequest) req).getHeader("X-Real-IP"));
MDC.put("REQUEST_USER", user);
MDC.put("REQUEST_BODY", bodyJson);
filterChain.doFilter((wrapper != null ? wrapper : req), res);
} catch (IOException | ServletException e) {
e.printStackTrace();
} finally {
MDC.clear();
}
}
}
The big trick in that filter is obtaining the POST or PATCH request body without consuming it and thereby prevening the regular request processing from getting it. Normally, you can only read the request body once. So we create a RequestWrapper and a ServletInputStreamWrapper which allow us to extract a copy of the request's input stream (body). The code for these classes looks like:
public class RequestWrapper extends HttpServletRequestWrapper {
private byte[] body;
public RequestWrapper(HttpServletRequest request) throws IOException {
super(request);
this.body = StreamUtils.copyToByteArray(request.getInputStream());
}
@Override
public ServletInputStream getInputStream() throws IOException {
return new ServletInputStreamWrapper(this.body);
}
}
public class ServletInputStreamWrapper extends ServletInputStream {
private InputStream inputStream;
public ServletInputStreamWrapper(byte[] body) {
this.inputStream = new ByteArrayInputStream(body);
}
@Override
public boolean isFinished() {
try {
return inputStream.available() == 0;
} catch (Exception e) {
return false;
}
}
@Override
public boolean isReady() {
return true;
}
@Override
public void setReadListener(ReadListener listener) {
// no need to implment this method
}
@Override
public int read() throws IOException {
return this.inputStream.read();
}
}
With all this in place, we now get nice Slack messages for errors providing request data and stack trace. The final result looks like:
.NET Framework Application with Application_Error handler
For the .NET Framework application its much simpler. In our Global.asax.cs file (where we create our application subclass of System.Web.HttpApplication) we define the Application_Error hook which allows us access to the request data, and then we simply send it to Slack utilizing the Slack.Webhooks package.
public class MvcApplication : System.Web.HttpApplication
{
private static readonly bool slackEnabled = Convert.ToBoolean(ConfigurationManager.AppSettings["slackEnabled"]);
private static readonly string slackURL = ConfigurationManager.AppSettings["slackURL"];
private static readonly string slackChannel = ConfigurationManager.AppSettings["slackChannel"];
private static readonly SlackClient slackClient = new SlackClient(slackURL);
private static readonly string environment = ConfigurationManager.AppSettings["environmentMode"];
protected void Application_Error(object sender, EventArgs e)
{
Exception ex = null;
// make sure whatever we do here doesn't generate any exceptions and generate a loop
try
{
ex = Server.GetLastError();
string requestType = HttpContext.Current.Request.RequestType;
string requestURL = Convert.ToString(HttpContext.Current.Request.Url);
string requestReferrer = Convert.ToString(HttpContext.Current.Request.UrlReferrer);
string requestBrowser = HttpContext.Current.Request.Browser.Browser + " " + HttpContext.Current.Request.Browser.Version;
string requestPlatform = HttpContext.Current.Request.Browser.Platform;
bool requestIsAuthenticated = HttpContext.Current.Request.IsAuthenticated;
string requestUserAgent = HttpContext.Current.Request.UserAgent;
string currentUser = User.Identity.Name?.Split('\\')[1];
string requestUserAddress = HttpContext.Current.Request.UserHostAddress;
string requestForwardedForAddress = HttpContext.Current.Request.Headers.Get("X-Forwarded-For");
Stream requestInputStream = HttpContext.Current.Request.InputStream;
requestInputStream.Seek(0, SeekOrigin.Begin);
string requestBody = new StreamReader(requestInputStream).ReadToEnd();
string logInfoString =
"\n User: " + currentUser
+ "\n Request type: " + requestType
+ "\n Request URL: " + requestURL
+ "\n Referrer: " + requestReferrer
+ "\n Browser: " + requestBrowser
+ "\n Platform: " + requestPlatform
+ "\n UserAgent: " + requestUserAgent
+ (requestIsAuthenticated ? "" : ("\n IsAuthenticated: " + requestIsAuthenticated))
+ "\n Source address: " + requestUserAddress + (string.IsNullOrEmpty(requestForwardedForAddress) ? "" :
(" / " + requestForwardedForAddress));
string logInfoString = requestInfoString +
(string.IsNullOrEmpty(requestBody) ? "" : ("\n Request body: " + requestBody));
log.Error(logInfoString, ex);
SendSlackMessage("Application Error:", requestInfoString, ex, requestBody);
}
catch (Exception exc) {
// If we have issues getting any of the info above, at least log the exception
try
{
log.Error("Original exception: ", ex);
log.Error("Additionally, there was an exception in Application_Error: " + exc);
}
catch (Exception) { }
}
}
public static void SendSlackMessage(string title, string message, Exception exception, string requestBody)
{
// don't send to slack if disabled or running locally
if (!slackEnabled || environment == "local") return;
// add time and make the title bold so that messages posted in quick succession can be easily told apart
// (*stuff* makes it bold)
string slackText = "*" + DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss") + (title != null ? (" - " + title) : "") + "*";
if (message != null)
{
slackText += "\n" + message;
}
List<SlackAttachment> slackAttachments = new List<SlackAttachment>();
if (!string.IsNullOrWhiteSpace(requestBody))
{
var requestBodyAttachment = new SlackAttachment
{
Text = requestBody
};
slackAttachments.Add(requestBodyAttachment);
}
if (exception != null)
{
var slackAttachment = new SlackAttachment
{
Text = exception.ToString(),
Color = "#C20202"
};
slackAttachments = new List<SlackAttachment> { slackAttachment };
}
// local defaults. Comment out first line of the method to test locally if needed
string slackUser = ".NET Application";
string slackUserEmoji = Emoji.Wrench;
var slackMessage = new SlackMessage
{
Channel = slackChannel,
Text = slackText,
IconEmoji = slackUserEmoji,
Username = slackUser,
Attachments = slackAttachments
};
slackClient.PostAsync(slackMessage);
}
