Java Exceptions and How to Log Them Securely
Tags: java, logging
Published: 2020-05-12 15:31:38

<!-- wp:paragraph -->
<p>As a security consultant, I perform assessments across a wide variety of applications. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Throughout the applications I've tested, I've found it's common for them to suffer from some form of inadequate exception handling and logging.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p> <a href="https://www.scalyr.com/blog/get-started-quickly-java-logging/">Logging</a> and monitoring are often-overlooked areas, and due to increased threats against web applications, they've been added to the<a href="https://www.owasp.org/index.php/Category:OWASP_Top_Ten_Project"> OWASP Top 10</a> as the new number ten issue, under the name "<a href="https://www.owasp.org/index.php/Top_10-2017_A10-Insufficient_Logging%26Monitoring">Insufficient Logging and Monitoring</a>."</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>So what’s the problem here? Well, let’s take a look. </p>
<!-- /wp:paragraph -->

<!-- wp:image {"id":790,"align":"center"} -->
<div class="wp-block-image"><figure class="aligncenter"><img src="https://library.scalyr.com/2018/07/19175415/Java-Exceptions.png" alt="" class="wp-image-790"/></figure></div>
<!-- /wp:image -->

<!-- wp:more -->
<!--more-->
<!-- /wp:more -->

<!-- wp:heading -->
<h2>Logs? Who Needs Logs?</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>To start off, why do we even use logging? What’s the point?</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Not only is proper logging useful for debugging applications, but it also has serious implications for compliance and many benefits for forensics and incident response. </p>
<!-- /wp:paragraph -->

<!-- wp:image {"id":3775,"align":"left"} -->
<div class="wp-block-image"><figure class="alignleft"><img src="https://library.scalyr.com/2019/04/26084436/Copy-of-That-way-you-can-learn-what-caused-the-error-and-prevent-it-from-happening-again-in-the-future..png" alt="" class="wp-image-3775"/></figure></div>
<!-- /wp:image -->

<!-- wp:paragraph -->
<p>How do you know if someone is running a vulnerability scanner against your application? </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Or is attempting a brute force authentication attack to try and access user accounts? All of this is good to know, but there are other subtle things as well.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>The majority of successful attacks start with an attacker who probes the application and looks for weak points. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>The more an attacker can probe the application, the higher the chance that the attacker will find and successfully exploit the application.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p> Attackers rely on being able to go unnoticed, and since the breach detection rate is an <a href="https://www-01.ibm.com/common/ssi/cgi-bin/ssialias?htmlfid=SEL03130WWEN&amp;">average of 191 days</a>, the logs are often the only way that anyone can see what happened. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Not having this information makes it extremely difficult to assess who did what when and to what extent access was gained.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Create and Follow a Logging Strategy</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>It's very rare that I see an application that has an actual logging strategy. Most of the time, we implement logging as an afterthought. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>I guess that can be a strategy, but can we do better? I think we can.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>When you add <a href="https://www.scalyr.com/blog/application-logging-practices-adopt/">logging into the application</a>, it's a good idea to have an overall consistent strategy. Use the same logging framework across all of the applications wherever possible. </p>
<!-- /wp:paragraph -->

<!-- wp:image {"id":791,"align":"right"} -->
<div class="wp-block-image"><figure class="alignright"><img src="https://library.scalyr.com/2018/07/19175416/Pull-quote-Its-very-rare-that-I-see-an-application-that-has-an-actual-logging-strategy.png" alt="" class="wp-image-791"/></figure></div>
<!-- /wp:image -->

<!-- wp:paragraph -->
<p>This makes it easy to share configurations, such as message formats, and to adopt consistent logging patterns. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Consistency on when a message is a warning or an error and what logging levels to use also need to be documented. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>When logging anything, the message format should always contain at a minimum the timestamp, current thread identifier, caller identity, and source code information. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>All modern logging frameworks support this type of information out of the box.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Having all of this as part of your developer documentation would be a great way to create and maintain a consistent logging strategy across all of your business's applications.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Log the Complete Stack Trace</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>In many of the secure code reviews I’ve done, a mistake I commonly see is not logging the entire stack trace for an exception. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Take this hypothetical example, representative of the exact pattern I've seen many times in code reviews:</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted {"className":"lang:java decode:true"} -->
<pre class="wp-block-preformatted lang:java decode:true">public Customer findCustomerByName(String customerName) {
&nbsp;&nbsp;try {
&nbsp;&nbsp;&nbsp; Customer c = customerService.findByName(customerName);
&nbsp;&nbsp;  return c;
&nbsp;&nbsp;} catch (Exception ex) {
&nbsp;&nbsp;  LOG.error("Exception looking up customer by name: " + ex.getMessage());
  }
}</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>Now, there are a few things wrong with this example, but let’s just focus on handling the SQLException. Let’s say that in production you look at the logs and see this:</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted {"className":"lang:sh decode:true"} -->
<pre class="wp-block-preformatted lang:sh decode:true">2018-03-02 09:29:47.287 ERROR 5166 --- [nio-8090-exec-1] com.scalyr.controllers.DemoController&nbsp;&nbsp;&nbsp;&nbsp;: org.hibernate.exception.SQLGrammarException: error executing work</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>That doesn’t tell you a whole lot. What caused the SQLGrammarException?</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p> The logger classes all have an overload that takes a Throwable object and will handle constructing and writing out the stack trace.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>By changing the code slightly, we can get a clearer picture of what's going on:</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted -->
<pre class="wp-block-preformatted">public Customer findCustomerByName(String customerName) {
&nbsp;&nbsp;try {
&nbsp;&nbsp;&nbsp;&nbsp;Customer c = customerService.findByName(customerName);
&nbsp;&nbsp;  return c;
&nbsp;&nbsp;} catch (Exception ex) {
&nbsp;&nbsp;  LOG.error("Exception looking up customer by name: " + ex.getMessage(), ex);
&nbsp;&nbsp;}
  return null;
}</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>This code change we applied resulted in logging the full stack trace, which clearly shows some nefarious activity here (or fat fingers...).</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted -->
<pre class="wp-block-preformatted">2018-03-02 09:33:11.341 ERROR 5188 --- [nio-8090-exec-1] com.scalyr.controllers.DemoController&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;: org.hibernate.exception.SQLGrammarException: error executing work

org.hibernate.exception.SQLGrammarException: error executing work
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:63) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109) ~[hibernate-core-5.0.12.Final.jar:5.0.12.Final]
&amp;nbsp;&amp;nbsp;... omitted
&amp;nbsp;&amp;nbsp;at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-8.5.15.jar:8.5.15]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at java.lang.Thread.run(Thread.java:748) [na:1.8.0_144]
Caused by: java.sql.SQLSyntaxErrorException: malformed string: 'Acme''
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.jdbc.JDBCStatement.fetchResult(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.jdbc.JDBCStatement.executeQuery(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_144]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_144]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_144]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_144]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;... 105 common frames omitted
Caused by: org.hsqldb.HsqlException: malformed string: 'Acme''
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.error.Error.error(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.error.Error.error(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.ParserBase.read(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.ParserDQL.XreadPredicateRightPart(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;at org.hsqldb.ParserDQL.XreadBooleanPrimaryOrNull(Unknown Source) ~[hsqldb-2.4.0.jar:2.4.0]&amp;nbsp;
&amp;nbsp;&amp;nbsp;&amp;nbsp;&amp;nbsp;... 122 common frames omitted</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>Now if we were to see this in the logs, we can pretty immediately see what the issue is. Someone has attempted to look up a customer with the name of Acme’and it broke our SQL statement. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>This exception is a clear indicator of a SQL injection and could be easily missed if someone analyzes the logs and only sees the original message. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>They might not think much of it and move on to other issues, not catching a serious flaw.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Log All Java Exceptions</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>The “swallowing” of exceptions is another all-too-common issue I see. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>An exception is thrown somewhere in the application and the developer has a catch block intending to handle the exception, but for some reason forgets to come back to it or decides that it isn't important. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>The following example illustrates this problem:&nbsp;</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted -->
<pre class="wp-block-preformatted">public Customer findCustomerByName(String customerName) {
  try {
&nbsp;&nbsp;  Customer c = customerService.findByName(customerName);
&nbsp;&nbsp;&nbsp;&nbsp;return c;
&nbsp;&nbsp;} catch (Exception ex) {
&nbsp;   // todo: Log using the new logging strategy..
&nbsp;&nbsp;}
&nbsp; return null;
}</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>This practice is all too common from my experience and definitely warrants being called out. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Logging the exception, rethrowing it, or just not handling it at all results in no indication in the logs that anything went wrong with the application. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>There’s never a reason not to at least log an exception. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Swallowing exceptions like this results in hiding any problems with the underlying query or another abstraction, which may go unnoticed and may be the result of issues in business logic or a security flaw.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Don’t Return Exceptions to the User</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>When performing a security assessment of any kind, every piece of information you can learn about the application or its environment is potentially useful. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>A seemingly innocuous error message may be just what a consultant (or an attacker) needs. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>They could find the one exploit that may work against your system or greatly reduce the payloads needed to test for a SQL injection if an error message reveals something about the database system in use.&nbsp;</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>It’s also a common practice to simply return an exception message to the user through some kind of error handling. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>I come across this a lot when testing authentication systems, as in the following screenshot:</p>
<!-- /wp:paragraph -->

<!-- wp:image {"id":3785} -->
<figure class="wp-block-image"><img src="https://library.scalyr.com/2019/04/26090430/auth-exception-1024x582-1024x582.png" alt="" class="wp-image-3785"/></figure>
<!-- /wp:image -->

<!-- wp:paragraph -->
<p>The code that handles this might be doing something like this:</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted -->
<pre class="wp-block-preformatted">User findByUsername(String userName) throws UserNameNotFoundException {
  EntityManager em = entityManagerFactory.createEntityManager();
&amp;nbsp; return em.createQuery("from User where userName = :userName", User.class)
  .setParameter("userName", userName)
  .getSingleResult();
}</pre>
<!-- /wp:preformatted -->

<!-- wp:paragraph -->
<p>Later on, the exception is thrown and caught. The developer uses the exception message to construct an error that's passed along to the user. This results in the user being able to see the raw exception message.</p>
<!-- /wp:paragraph -->

<!-- wp:preformatted -->
<pre class="wp-block-preformatted">public String login(Model model, String username, String password) {
  try {
    // attempt to login user
&nbsp;&nbsp;&nbsp;&nbsp;userService.login(username, password);
  } catch (Exception ex) {
    model.addAttribute("error", ex.getMessage());
&nbsp;&nbsp;}
  return "login”;</pre>
<!-- /wp:preformatted -->

<!-- wp:heading -->
<h2><figure><img class=" wp-image-793 alignright" src="https://library.scalyr.com/2018/07/19175417/Pull-Quote-A-seemingly-innocuous-error-message-may-be-just-what-an-attacker-needs.png" alt="" width="299" height="253"></figure></h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>Not only is this bad practice as far as exception handling goes, but it also opens up the application to user account validation.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p> Depending on the type of application you're working on, this could be a risk in itself.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Never return the contents of an exception object to the user. Catch the exception, log it, and return a generic response.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p> You never know what information the exception message may contain as code evolves, and the message itself may change in the future.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Don’t Log Sensitive Information</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>I mentioned that logs can be useful for not only debugging but also for compliance, audit, and forensics. Because logs have many uses and we have a tendency to just “log everything,” they can be an incredible source of information.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>If logs contain usernames, passwords, session tokens, or other sensitive information, it really reduces the work for an attacker. </p>
<!-- /wp:paragraph -->

<!-- wp:image {"id":3788,"align":"center","width":512,"height":322} -->
<div class="wp-block-image"><figure class="aligncenter is-resized"><img src="https://library.scalyr.com/2019/04/26091754/Security-1024x643.jpeg" alt="" class="wp-image-3788" width="512" height="322"/></figure></div>
<!-- /wp:image -->

<!-- wp:paragraph -->
<p>Logs will reveal the inner workings and failures of an application, all of which an attacker can use to attack the application further. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Due to this, we need to view and treat logs as sensitive and keep them secure. We probably already know not to log the following information:</p>
<!-- /wp:paragraph -->

<!-- wp:list -->
<ul><li>Credit card numbers</li><li>Social security numbers</li><li>Passwords</li></ul>
<!-- /wp:list -->

<!-- wp:paragraph -->
<p>But the following types of information shouldn't be written to logs either:</p>
<!-- /wp:paragraph -->

<!-- wp:list -->
<ul><li>Session identifiers</li><li>Authorization tokens</li><li>Personal names</li><li>Telephone numbers</li><li>Information the user has opted out of (e.g., do not track)</li></ul>
<!-- /wp:list -->

<!-- wp:paragraph -->
<p>There’s another issue: some jurisdictions don’t allow certain information to be tracked, and doing so violates the law. </p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Knowing the compliance requirements of the application and the data it processes is extremely important.</p>
<!-- /wp:paragraph -->

<!-- wp:heading -->
<h2>Don’t Be in the Dark</h2>
<!-- /wp:heading -->

<!-- wp:paragraph -->
<p>While logging isn't a complex task, there's a lot of subtlety and balance in getting it right. Too little information won't be very valuable. Too much information can be overwhelming if not relevant or isn't handled properly.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p>Application logging isn't optional. Without adequate logs, you're truly in the dark.</p>
<!-- /wp:paragraph -->

<!-- wp:paragraph -->
<p><em>This post was written by&nbsp;<a href="http://www.caseydunham.com/">Casey Dunham</a>.&nbsp; Casey, who recently launched his own security business, is known for his unique approaches to all areas of application security, stemming from his 10+ year career as a professional software developer. His strengths include secure SDLC development consulting; threat modeling; developer training; and auditing web, mobile, and desktop applications for security flaws.</em></p>
<!-- /wp:paragraph -->