table 首先冻结
用塞西尔·德·米勒(Cecil B. de Mille) 的话来形容:“撰写博客文章的方法是从堆栈跟踪开始,直至达到高潮 ” –在这里:
详细信息还不重要,但是从100ft视图中,您可以看到较长的堆栈跟踪,并且有多个相互包裹的异常( 引起 )。 我们将回到此堆栈跟踪,但首先要了解一些基础知识。 如果抛出异常,则会以某种方式记录日志,以显示异常发生时瞬间堆栈的外观。 在最底部,您将看到静态的main()或Thread.run() ,该方法通过调用直到第一个堆栈跟踪行的方法进行处理,该行指示实际抛出异常的位置。 这非常方便,因为您可以看到导致异常的整个控制流程:
public class BookController {private final BookService bookService = new BookService();public void alpha() { beta(); }private void beta() { gamma(); }private void gamma() { bookService.delta(); }public static void main(String[] args) {new BookController().alpha();}
}class BookService {private final BookDao bookDao = new BookDao();public void delta() { epsilon(); }private void epsilon() { zeta(); }private void zeta() { bookDao.eta(); }
}class BookDao {public void eta() { theta(); }private void theta() { iota(); }public void iota() { throw new RuntimeException("Omega server not available"); }
}
如果您不知道希腊字母 ,则可以从堆栈跟踪中开始学习(请记住,控制流从底部开始并一直向上):
java.lang.RuntimeException: Omega server not availableat BookDao.iota(BookController.java:50)at BookDao.theta(BookController.java:48)at BookDao.eta(BookController.java:46)at BookService.zeta(BookController.java:41)at BookService.epsilon(BookController.java:39)at BookService.delta(BookController.java:37)at BookController.gamma(BookController.java:22)at BookController.beta(BookController.java:20)at BookController.alpha(BookController.java:18)at BookController.main(BookController.java:26)
太好了吧? 从上到下阅读时,您可以说: iota()由theta()调用,而eta()则调用…清晰而简单。 但是,如果有人决定包装原始异常并重新抛出该异常怎么办?
public class BookController {private static final Logger log = LoggerFactory.getLogger(BookController.class);private final BookService bookService = new BookService();public void alpha() { beta(); }private void beta() { gamma(); }private void gamma() {try {bookService.delta();} catch (Exception e) {throw new RuntimeException("Sorry, try again later", e);}}public static void main(String[] args) {try {new BookController().alpha();} catch (Exception e) {log.error("", e);}}
}class BookService {private final BookDao bookDao = new BookDao();public void delta() { epsilon(); }private void epsilon() { zeta(); }private void zeta() {try {bookDao.eta();} catch (Exception e) {throw new RuntimeException("Unable to save order", e);}}
}class BookDao {public void eta() { theta(); }private void theta() { iota(); }public void iota() {try {throw new RuntimeException("Omega server not available");} catch (Exception e) {throw new RuntimeException("Database problem", e);}}
}
现在快速:在堆栈跟踪中找到根本原因!
java.lang.RuntimeException: Sorry, try again laterat BookController.gamma(BookController.java:26)at BookController.beta(BookController.java:20)at BookController.alpha(BookController.java:18)at BookController.main(BookController.java:32)
Caused by: java.lang.RuntimeException: Unable to save orderat BookService.zeta(BookController.java:51)at BookService.epsilon(BookController.java:45)at BookService.delta(BookController.java:43)at BookController.gamma(BookController.java:24)... 8 common frames omitted
Caused by: java.lang.RuntimeException: Database problemat BookDao.iota(BookController.java:66)at BookDao.theta(BookController.java:60)at BookDao.eta(BookController.java:58)at BookService.zeta(BookController.java:49)... 11 common frames omitted
Caused by: java.lang.RuntimeException: Omega server not availableat BookDao.iota(BookController.java:64)... 14 common frames omitted
原来main()不再是最后一行。 更糟糕的是,一切似乎都出现了乱码,请尝试再次阅读希腊字母…现在让我们回到原始的堆栈跟踪中。 它来自Spring框架启动失败,想象它可能长达几页。
为了方便起见,我添加了箭头来标记您重建控制流所应遵循的路径:从红色箭头的尾部( Thread.run() )开始,在中间的某个位置向上,然后…跳至橙色箭头的尾部。 从橙色箭头的头部跳到绿色箭头的尾巴,依此类推...不是很直观,您不觉得吗? 这个红色的椭圆显示了什么? 是的,这是失败的根本原因(最内部的异常)。 另一方面,在最开始打印的异常(通常是您一开始就读到的异常 )说明了创建DefaultAnnotationHandlerMapping#0时发生的错误 (是什么?)真正的错误( 没有匹配的bean类型…… )被巧妙地隐藏了……
那么这个新功能到底是什么呢? 还是我们的简单例子。 升级到0.9.30之后,只需在日志记录模式的末尾添加%rEx (或等效的%rootException ):
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"><encoder><pattern>%d{ISO8601} | %-5level | %thread | %logger{1} | %m%n%rEx</pattern></encoder>
</appender>
这将替换为我亲自贡献的默认堆栈跟踪打印路由。 现在将打印相同的希腊程序:
java.lang.RuntimeException: Omega server not availableat BookDao.iota(BookController.java:64)
Wrapped by: java.lang.RuntimeException: Database problemat BookDao.iota(BookController.java:66)at BookDao.theta(BookController.java:60)at BookDao.eta(BookController.java:58)at BookService.zeta(BookController.java:49)
Wrapped by: java.lang.RuntimeException: Unable to save orderat BookService.zeta(BookController.java:51)at BookService.epsilon(BookController.java:45)at BookService.delta(BookController.java:43)at BookController.gamma(BookController.java:24)
Wrapped by: java.lang.RuntimeException: Sorry, try again laterat BookController.gamma(BookController.java:26)at BookController.beta(BookController.java:20)at BookController.alpha(BookController.java:18)at BookController.main(BookController.java:32)
请仔细将其与先前的输出进行比较。 首先,第一行指出了问题所在。 在大多数情况下,您都无需跳过“ 由...引起的 ”例外,您可能会跳过其余部分。 其次,控制流是不间断且连续的–您仍然可以从上至下阅读,反之亦然。 最后但并非最不重要的一点是–同时保留了异常被包裹的事实,但不会使堆栈跟踪混乱。
现在您应该看到利用%rEx打印的原始Spring异常:
观察结果完全相同:问题的根本原因从一开始就出现,从而缩短了需要研究问题的时间。 同样,在分析控制流时,不会跳跃-Thread.main()位于底部,您可以连续读取底部到顶部的轨迹。
如果您使用堆栈跟踪(在开发中或在生产/支持中)进行大量工作–请考虑切换到根本原因优先日志记录。 每次您分析特定异常时,它将节省您几秒钟的时间。 但是我还注意到,经验不足的开发人员有时甚至不知道“ 由...引起的 ”规则: 找到第一个例外,然后查看最后一个 “ 由...引起的 ” –根本不知道问题是什么,只查看最外面,最不具体,最通用的错误。 这也将对他们有帮助。
顺便说一下,如果您避免完全包装和重新抛出异常,则可以避免所有这些麻烦。 我知道,我们经常会因检查异常而被迫这么做……
参考: 日志异常的根源首先来自我们的JCG合作伙伴Tomek Nurkiewicz,位于NoBlogDefFound
编码愉快! 不要忘记分享!
相关文章:
- Java日志混乱
- 正确记录应用程序的10个技巧
- 使用AspectJ,Javassist和Java Proxy进行代码注入的实用介绍
- Java最佳实践系列
- 每个程序员都应该知道的事情
- 生存在荒野西部开发过程中的9条提示
- 软件设计法则
翻译自: https://www.javacodegeeks.com/2011/09/logging-exceptions-root-cause-first.html
table 首先冻结