当应用程序完成请求所需的时间比预期时间长时,请求可能会被记录为缓慢或挂起。Liberty的请求计时功能(Request Timing feature)可以自动检测缓慢和挂起的请求,并提供详细信息以帮助您找到延迟的根本原因。

请求计时功能(Request Timing feature)可识别运行时间超过慢速请求阈值的传入请求。请求计时功能会在请求发生时记录缓慢和挂起的请求,因此您无需再次重现问题即可收集更多数据。除了慢速和挂起请求阈值的全局设置之外,您还可以为特定 Servlet 或 JDBC 请求设置阈值。

缓慢请求的检测

造成请求缓慢的可能原因有,请求的代码路径长度过长,或者请求所依赖的资源繁忙等。用户需要知道在处理该请求期间发生了哪些操作,以及请求的处理阶段。当请求运行时间超过慢速请求阈值时,请求计时功能会在消息日志文件中生成警告消息。该消息包含有关请求和构成请求的事件的详细信息。默认阈值为 10 秒。以下示例显示了日志消息的格式:

TRAS0112W: Request <(Request ID)> has been running on thread <THREADID> for at least <DURATION>.
The following stack trace shows that this thread is currently running.
<STACK TRACE>
<DURATION AND OPERATIONS Table>

请求 ID 可用于搜索与请求对应的日志和跟踪消息。如果使用二进制日志记录,则可以使用 binary log 命令搜索具有相同 requestID 扩展名的日志和跟踪条目。STACK TRACE 指示正在运行的方法。在 STACK TRACE 之后,DURATION AND OPERATIONS 表提供包含请求的持续时间和操作的日志内容。“持续时间”列指示请求的相应操作所花费的时间。“持续时间”列中显示的加号 (+) 表示请求中仍在运行的事件。“持续时间”列还包括不带加号的持续时间,以指示相应的操作在指定的持续时间内完成。“操作”列显示指定操作的“事件类型”和可选的“上下文信息”。

该消息可帮助您分析请求速度缓慢的原因,但很难确定请求是在此时挂起还是仍在缓慢运行。为了解决此问题,在 slowRequestThreshold 属性指定的时间间隔内,任何慢速请求都会显示三条消息。堆栈跟踪数据提供有关正在运行的方法的信息,而请求数据提供有关请求的详细信息,例如请求 ID 和持续时间。这三种不同的堆栈跟踪和请求数据通过查看线程当前正在运行的内容,帮助您更好地了解请求出错的位置。除非请求的持续时间超过挂起的请求检测阈值,否则不会记录有关请求的进一步警告。

挂起请求的检测

花费时间超过挂起请求阈值的请求通常会因无法访问共享资源而被阻塞,例如,仅允许串行访问并按顺序传输信息的代码部分。这种较长的请求可能会被挂起,并且可能会被阻塞很长时间甚至无限期。当两个线程被阻塞以等待彼此返回共享资源时,就会发生一种特殊形式的挂起请求,称为死锁。对于挂起的请求,用户需要知道所有线程在处理过程中的位置,以及线程正在等待的锁。

如果请求超过挂起的请求阈值,那么请求计时功能会在消息日志文件中生成一条警告消息,其中包含请求的详细信息和构成请求的事件。并且生成连续的三个 javacore文件,每两个javacore文件的间隔为 1 分钟。如果检测到新请求,则会创建更多javacore文件。

以下日志消息示例显示了超过 hungRequestThreshold 属性的请求的日志消息。默认的hung请求持续时间阈值为 10 分钟。以下示例中配置的值为 4 分钟。

[WARNING ] TRAS0114W: Request AAA7WlpP7l7_AAAAAAAAAAA was running on thread 00000021 for at least 240001.015ms. The following table shows the events that have run during this request.
Duration Operation
240001.754ms + websphere.servlet.service | TestWebApp | TestServlet?sleepTime=480000
0.095ms       websphere.session.setAttribute | mCzBMyzMvAEnjMJJx9zQYIw |userID
0.007ms       websphere.session.setAttribute | mCzBMyzMvAEnjMJJx9zQYIw | visitCount

请求计时功能的配置

缓慢和挂起请求的阈值是通过在server.xml 文件内<requestTiming/>中设置 slowRequestThreshold 和 hungRequestThreshold 来配置的。此设置为所有定时请求设置一个缓慢和挂起的请求阈值。您还可以为不同类型的请求设置不同的缓慢和挂起请求阈值。server.xml 文件中嵌入 的<servletTiming/> 或者 <jdbcTiming/> 配置将覆盖 <requestTiming/> 中定义的已配置的缓慢和挂起请求阈值。<servletTiming/>配置可以按应用程序名称和/或 Servlet 名称设置缓慢和挂起请求阈值。<jdbcTiming/>配置可以按数据源名称和/或 sql 字符串设置缓慢和挂起请求阈值。

配置示例如下图所示。

参考文档:

https://www.ibm.com/docs/en/was-liberty/base?topic=liberty-slow-hung-request-detection
https://openliberty.io/docs/latest/slow-hung-request-detection.html

类似文章