【问题标题】:Requests take too much time in Tomcat 8 on peak time在 Tomcat 8 中,请求在高峰时间花费了太多时间
【发布时间】:2018-03-19 21:45:57
【问题描述】:

我已经用以下配置配置了tomcat:

<Connector port="8080" protocol="HTTP/1.1"
           connectionTimeout="20000"
           maxThreads="500"
           maxConnections="20000"
           acceptCount="150"
           etc... />

AJP 连接器、maxThreads=500acceptCount="150" 的编号相同。

它大部分时间都可以正常工作,但在高峰时间,当我的请求比平时多得多时,响应时间太长。有时超过 15 秒,在极少数情况下超时。它可能看起来不错,因为 maxThreads=500 并且我有几千个请求,但是,在服务器状态上我看到:

最大线程数:500 当前线程数:17 当前线程繁忙:1 保持 活动套接字数:1

到目前为止我看到的currentThreadCount的最大数量是27。如果连接这么多,tomcat不应该创建更多线程(最多500个)以更快地响应吗?

那么,我做错了什么?我错过了什么?我有 2 核 CPU(高峰时段的最大使用量约为 10%)和 2GB 的 RAM(最大使用量为 60%)。

关于网络应用的简短信息:通常,每个用户每个会话至少发出 2 个请求:静态 JSON 响应和 1 个数据库查询。在高峰期,我有 15-20k 活跃用户,但我不知道每秒收到多少请求。但是,从 5k 活跃用户开始响应缓慢。

我还增加了应用程序属性的最大活动连接数,但性能没有变化,我当前的 application.properties:

spring.jpa.hibernate.ddl-auto=update
spring.datasource.driverClassName=com.mysql.jdbc.Driver
spring.datasource.url=jdbc:mysql://localhost:3306/database_name
spring.datasource.username=$username$
spring.datasource.password=$password$
spring.datasource.tomcat.max-active=200
spring.datasource.tomcat.max-wait=10000
spring.datasource.tomcat.max-idle=50
spring.datasource.tomcat.min-idle=10
spring.datasource.tomcat.initial-size=10

更新 我将默认的JDBC 连接池更改为Hikari 并使用以下配置并启用了jta,但是在高峰时间上没有感觉到任何差异:

spring.jta.enabled=true
spring.datasource.hikari.maximum-pool-size=125
spring.datasource.hikari.minimum-idle=5

我在下面添加数据库查询。查询结果稍后添加到另一个对象中并作为 ResponseBody 返回。

@Query("select new ObjectClass(s.id, s.a, s.b, s.c") from TableName s " +
        "where s.x > :param order by id desc")
List<ObjectClass> getObjects(@Param("param") long param);

CPU 使用率没有增加,RAM 几乎一半空闲,如果我有太多请求,我不应该在服务器上超载吗?相反,我的响应时间很慢。因此,我想我有一个需要解决的配置问题。

-Xms512M -Xmx1024M

高峰期挂掉的应用:

活动会话:3243 会话计数:475330 最大活动会话:4685 拒绝会话创建:0 过期会话:472105 最长会话活动时间:7457 秒平均会话活动时间:9 秒处理时间:3177 毫秒 加载的 JSP:0 重新加载的 JSP:0

堆栈跟踪:

"Attach Listener" #502 daemon prio=9 os_prio=0 tid=0x00007fde58007800 nid=0x3ff waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Abandoned connection cleanup thread" #69 daemon prio=5 os_prio=0 tid=0x00007fde6c03e800 nid=0xa44 in Object.wait() [0x00007fde471ba000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000000c259e618> (a java.lang.ref.ReferenceQueue$Lock)
    at com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:64)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-exec-25" #68 daemon prio=5 os_prio=0 tid=0x00007fde40016000 nid=0x741 waiting on condition [0x00007fde35fe0000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1cc6758> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-exec-11" #54 daemon prio=5 os_prio=0 tid=0x00007fde38041800 nid=0x733 waiting on condition [0x00007fde36fee000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1cc6758> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-AsyncTimeout" #52 daemon prio=5 os_prio=0 tid=0x00007fde884e8800 nid=0x732 waiting on condition [0x00007fde370ef000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.coyote.AbstractProtocol$AsyncTimeout.run(AbstractProtocol.java:1211)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-Acceptor-0" #51 daemon prio=5 os_prio=0 tid=0x00007fde884e6800 nid=0x731 runnable [0x00007fde371f0000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
    - locked <0x00000000c019d7e8> (a java.lang.Object)
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:455)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-ClientPoller-1" #50 daemon prio=5 os_prio=0 tid=0x00007fde884e4800 nid=0x730 runnable [0x00007fde372f1000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x00000000c1da2fa0> (a sun.nio.ch.Util$3)
    - locked <0x00000000c1da2f90> (a java.util.Collections$UnmodifiableSet)
    - locked <0x00000000c1d5b1e0> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:787)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-ClientPoller-0" #49 daemon prio=5 os_prio=0 tid=0x00007fde884d6000 nid=0x72f runnable [0x00007fde373f2000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x00000000c1d510d8> (a sun.nio.ch.Util$3)
    - locked <0x00000000c1d510c8> (a java.util.Collections$UnmodifiableSet)
    - locked <0x00000000c1ce78c0> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:787)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-exec-10" #48 daemon prio=5 os_prio=0 tid=0x00007fde884c7000 nid=0x72e waiting on condition [0x00007fde374f3000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1cc6758> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-exec-2" #40 daemon prio=5 os_prio=0 tid=0x00007fde884b7000 nid=0x726 waiting on condition [0x00007fde37cfb000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1cc6758> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"ajp-nio-8009-exec-1" #39 daemon prio=5 os_prio=0 tid=0x00007fde884b5000 nid=0x725 waiting on condition [0x00007fde37dfc000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1cc6758> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:85)
    at org.apache.tomcat.util.threads.TaskQueue.poll(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-127.0.0.1-8080-AsyncTimeout" #38 daemon prio=5 os_prio=0 tid=0x00007fde884b3000 nid=0x724 waiting on condition [0x00007fde37efd000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.coyote.AbstractProtocol$AsyncTimeout.run(AbstractProtocol.java:1211)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-127.0.0.1-8080-Acceptor-0" #37 daemon prio=5 os_prio=0 tid=0x00007fde884b1800 nid=0x723 runnable [0x00007fde37ffe000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
    at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
    - locked <0x00000000c01a03b8> (a java.lang.Object)
    at org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:455)
    at java.lang.Thread.run(Thread.java:748)

"http-nio-127.0.0.1-8080-exec-1" #25 daemon prio=5 os_prio=0 tid=0x00007fde88324000 nid=0x717 waiting on condition [0x00007fde46db8000]
   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c1d9c4e0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:103)
    at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:31)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" #24 daemon prio=5 os_prio=0 tid=0x00007fde88323000 nid=0x716 waiting on condition [0x00007fde476bb000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1355)
    at java.lang.Thread.run(Thread.java:748)

"Abandoned connection cleanup thread" #22 daemon prio=5 os_prio=0 tid=0x00007fde4ca72800 nid=0x6f5 in Object.wait() [0x00007fde45c22000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000000c102c4b0> (a java.lang.ref.ReferenceQueue$Lock)
    at com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:64)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

"Tomcat JDBC Pool Cleaner[1595428806:1507838479700]" #21 daemon prio=5 os_prio=0 tid=0x00007fde4ca5b800 nid=0x6f4 in Object.wait() [0x00007fde470b9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.util.TimerThread.mainLoop(Timer.java:552)
    - locked <0x00000000c0f6fe80> (a java.util.TaskQueue)
    at java.util.TimerThread.run(Timer.java:505)

"NioBlockingSelector.BlockPoller-2" #13 daemon prio=5 os_prio=0 tid=0x00007fde8847e000 nid=0x66f runnable [0x00007fde478bd000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x00000000c019bd40> (a sun.nio.ch.Util$3)
    - locked <0x00000000c019bd30> (a java.util.Collections$UnmodifiableSet)
    - locked <0x00000000c019bbf8> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioBlockingSelector$BlockPoller.run(NioBlockingSelector.java:339)

"NioBlockingSelector.BlockPoller-1" #12 daemon prio=5 os_prio=0 tid=0x00007fde8846f800 nid=0x66e runnable [0x00007fde479be000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
    at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
    at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
    at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
    - locked <0x00000000c019ec10> (a sun.nio.ch.Util$3)
    - locked <0x00000000c019ec00> (a java.util.Collections$UnmodifiableSet)
    - locked <0x00000000c019ead8> (a sun.nio.ch.EPollSelectorImpl)
    at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
    at org.apache.tomcat.util.net.NioBlockingSelector$BlockPoller.run(NioBlockingSelector.java:339)

"GC Daemon" #11 daemon prio=2 os_prio=0 tid=0x00007fde883f9000 nid=0x66b in Object.wait() [0x00007fde741c6000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000c02f16d8> (a sun.misc.GC$LatencyLock)
    at sun.misc.GC$Daemon.run(GC.java:117)
    - locked <0x00000000c02f16d8> (a sun.misc.GC$LatencyLock)

"AsyncFileHandlerWriter-1510467688" #10 daemon prio=5 os_prio=0 tid=0x00007fde88168800 nid=0x63e waiting on condition [0x00007fde7475c000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000c02f16e8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
    at java.util.concurrent.LinkedBlockingDeque.pollFirst(LinkedBlockingDeque.java:522)
    at java.util.concurrent.LinkedBlockingDeque.poll(LinkedBlockingDeque.java:684)
    at org.apache.juli.AsyncFileHandler$LoggerThread.run(AsyncFileHandler.java:160)

"Service Thread" #7 daemon prio=9 os_prio=0 tid=0x00007fde880af000 nid=0x62e runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007fde880ac000 nid=0x62d waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007fde880a9000 nid=0x62c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007fde880a7000 nid=0x62b runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fde88080000 nid=0x625 in Object.wait() [0x00007fde74f33000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
    - locked <0x00000000c02f7408> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007fde8807b800 nid=0x622 in Object.wait() [0x00007fde75034000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    at java.lang.Object.wait(Object.java:502)
    at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
    - locked <0x00000000c02f7490> (a java.lang.ref.Reference$Lock)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" #1 prio=5 os_prio=0 tid=0x00007fde8800a800 nid=0x589 runnable [0x00007fde8f6af000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
    at java.net.ServerSocket.implAccept(ServerSocket.java:545)
    at java.net.ServerSocket.accept(ServerSocket.java:513)
    at org.apache.catalina.core.StandardServer.await(StandardServer.java:466)
    at org.apache.catalina.startup.Catalina.await(Catalina.java:744)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:690)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:355)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:495)

"VM Thread" os_prio=0 tid=0x00007fde88073800 nid=0x5fd runnable 

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fde8801f800 nid=0x597 runnable 

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fde88021000 nid=0x598 runnable 

"VM Periodic Task Thread" os_prio=0 tid=0x00007fde880bd800 nid=0x62f waiting on condition 

JNI global references: 317

更新: 虽然我还没有解决我的问题,但@Per Huss 的回答将我推向了正确的方向,分别分析每个线程并找到问题。我现在必须奖励我的赏金,因此,我将奖励给他。不过,我感谢所有在这里发表评论的人,因为所有 cmets 都帮助我学习了新的东西。

更新 2: 看起来问题出在apache内。在高峰时间,即使是静态页面的响应时间也很慢,即使是来自其他应用程序的页面也是如此。包括tomcat 管理器。所以,我将prefork 更改为mpm_worker,目前正在测试不同的配置。我很快就会用结果更新这个帖子。

【问题讨论】:

  • 如果由于某种原因 tomcat 不能快速处理您的请求或响应时间超过 15 秒,您会减少 apache 可以处理的请求数。 Tomcat 配置为并行处理 400 个请求,并且默认的 acceptCount 为 100。因此,您的 Tomcat 能够吃掉 500 个请求,而不是默认配置 - 至少:依赖于 jvm 和平台的连接可能更多请求排队。
  • 在不知道这个 webapp 做什么的情况下很难回答这个问题。您使用的是哪种数据库(如果有)?等等等等。
  • 我正在使用 MySql 和 wepapp 对数据库进行简单的查询。我还将在有关用户的问题中添加几行
  • 你在数据库中搜索的这个参数经常变化?,你考虑过使用缓存吗? (番石榴,榛树)?
  • @Makoton,也许不是那么频繁,但它们会改变。首先,我想使用服务器的全部容量,然后才在代码中添加一些优化。因为我将很快添加新的表/服务,所以我最终会再次遇到同样的问题。很快,我将使用缓存,但只有在我解决了这个问题之后:)

标签: java spring hibernate tomcat spring-boot


【解决方案1】:

恐怕这个问题目前除了猜测之外没有足够的信息。低 CPU 使用率表明您的 java 进程正在等待某些东西,这可能是获取与数据库的连接、等待查询结果或其他任何东西。在尝试修复它之前,我会先查看导致等待的是什么。一种方法是运行

jstack <pid>

(其中&lt;pid&gt; 将是您的进程的 pid)在高峰期。它将列出每个线程的堆栈跟踪。您可能能够从中发现问题,或者您可以将其粘贴到问题中,也许社区可以帮助您。祝你调音好运!

【讨论】:

  • 运行 jstack 时出现错误。 Unable to deduce type of thread from address。我检查了,互联网上充满了那个错误,我会尝试解决并检查响应。感谢您的回复
  • 如果你在 Linux 上,你可以在kill -3 后面加上 pid,然后在进程的 stdout 上转储...
  • 我遇到了异常,因为可以在进程上运行 jstack,只有启动它的用户并且我正在使用 root 尝试它。我在问题中添加了堆栈跟踪,但不是从现在开始。我只会在 2 天后达到高峰。至少,现在,我知道从哪里开始挖掘 :)
【解决方案2】:

您可以允许任意数量的线程,但是如果查询数量增加,那么 RDBMS 的响应时间会变差,这可能是您的根本原因。

你需要确定他的瓶颈在哪里。创建一个虚拟页面并像疯子一样从几台计算机向它发出请求。如果虚拟页面及时响应,那么您的问题与连接数以及更多与您的数据库的关系松散相关。很有可能是这种情况。

查看您的数据库,确保您的架构处于正常形式。此外,如果您经常按某些列搜索,请确保创建正确的索引。查看您的查询并观察它们是否过慢。如果是这样,请优化它们。缓存一些变化不是太频繁的数据,然后重复使用。

【讨论】:

  • 很可能是数据库处理不了。目前,我只有一个少于 1k 行的表,每个表有 14 列。数据库请求并不慢,可能问题在于对数据库的请求数量。我去看看,谢谢
  • @Javanshir 您可以尝试通过模仿来自多线程独立应用程序的一些请求来重现该问题。如果您这样做并且设法找到重现问题的方法,那么您将非常接近您的问题的答案。
  • 我两次增加了最大活动连接数 (spring.datasource.tomcat.max-active=200),但是,我没有看到任何改进。就像之前一样,CPU 使用率从 1% 增加到 4%,RAM 使用率从 47% 增加到 52%,在峰值时间并且性能没有变化。
  • @Javanshir RAM 使用意味着写入大量数据。看来你需要看看你的查询。
  • 我在问题中添加了我的数据库查询,它只是一个简单的 JPA 查询。没有连接,一点也不复杂。
【解决方案3】:

我终于解决了我的问题。事实上,是 apache 不允许足够的连接。首先,我将prefork 更改为mpm worker。后来我增加了MaxRequestWorkers的数量。

<IfModule mpm_worker_module>
    StartServers             2
    MinSpareThreads          50
    MaxSpareThreads          125
    ThreadLimit              64
    ThreadsPerChild          25
    ServerLimit              5000
    MaxRequestWorkers        5000
    MaxConnectionsPerChild   4500

早些时候,我的响应时间已经很慢,有 3000 个活跃用户。使用新配置,即使 17000 名活跃用户也没有增加响应时间,而且工作正常。正如预期的那样,CPU 使用率和 RAM 在高峰时间增加,然后恢复正常。

【讨论】:

    【解决方案4】:

    使用 spring 时默认为 Tomcat。如何使用 Netty 或 Undertow 或 Jetty 获得更好的性能。还请记住,尽管有 2 核 CPU,但实际上并没有 500 个线程。

    上述回答如何实际模拟您的应用程序对流量的反应可能是最好的方法。如果使用关系数据库,请记住写入甚至比读取慢十倍(您可以在 Cassandra 文档中看到一些有趣的统计数据)。如果使用休眠,您可能还想查找 n+1 问题。最好的方法:编写一个集成测试,记录发送到数据库的 sql。如果您的测试发送 51 而不是一个查询,那么您就有了。

    【讨论】:

    • 我的观点是:我应该在 CPU 或 RAM 上过载,或者至少在活动线程的数量上,我得到的只是缓慢的响应。虽然 500 个线程中只有 15-27 个线程处于活动状态。所以,问题可能是数据库的默认设置,我会尽快检查
    • 请记住,您的代码在 JVM 中运行,它有选项告诉它可以消耗多少内存。因此,即使您的应用程序占用了所有 JVM 分配的内存,它也可能不会占用您所有的 RAM 或 CPU。 500个线程,表示tomcat有500个静态分配的线程。所以你的请求正在争夺线程使用。
    • JVM Free memory: 416.27 MB Total memory: 546.00 MB Max memory: 910.50 MB
    【解决方案5】:

    如果有这么多连接,tomcat不应该创建更多线程吗 (最多 500 个)响应更快?

    => 根据 Tomcat8 文档,如果收到的并发请求多于当前可用的请求处理线程所能处理的数量,则将创建额外的线程,直至配置的最大值(maxThreads 属性的值)。如果接收到更多同时请求,它们会堆积在连接器创建的服务器套接字中,直到配置的最大值(acceptCount 属性的值)。

    因此,您的 tomcat 必须根据需要创建线程。此外,Tomcat 8 默认工作在 NIO 模式,这意味着一个线程可以服务多个请求。您可以通过在负载测试期间启动诸如“jvisualvm”之类的监视工具来确认该行为。

    活动线程:这显示了当前活动/活动线程的数量,包括守护线程和非守护线程(当前正在运行)。

    Live Peak:这给出了自 Java 虚拟机启动或峰值重置以来活动线程的峰值计数。

    守护线程:这给出了当前活动守护线程的数量。

    总线程数:这给出了自 Java 虚拟机启动以来创建和启动的线程总数。

    那么,我做错了什么?我错过了什么?我有 2 核 CPU(最大 高峰时段的使用率约为 10%)和 2GB 的 RAM(最大使用率 60%)。CPU 使用率 没有增长,如果我有太多,RAM 几乎是一半空闲 请求,我不应该在服务器上超载吗?相反,我只是得到 响应时间慢。

    =>IMO,线程在从数据库获取数据时阻塞。这可能是由于在加载期间查询性能不佳。我建议启用“hibernate.show_sql”捕获 SQL。检查 SQL 的执行计划,确保正在应用索引。您还可以通过在 SQL 客户端上执行查询来检查加载期间查询的性能。

    【讨论】:

    • 我将开始使用 jvisualvm 来更好地分析我的 webbapps。谢谢你的信息:)
    【解决方案6】:

    在这些bug中,首先我们应该确定问题出在哪里。这里给出了调试这些类型问题的行动计划:

    例如你的情况

    用户向 tomcat 发出请求,然后它会将其提供给您的应用程序。

    首先,检查问题出在哪里,即以下地方可能存在问题:

    1. 您的任何应用程序 api 或所有 api 都开始占用时间,但 tomcat 线程是免费的
    2. 您的 tomcat 线程不是空闲的,并且每个线程的处理都需要时间,因此会出现延迟
    3. 您的数据库开始需要时间
    4. 当您查询数据库时,可能会出现更多数据正在加载到您的应用程序中并且开始出现一些 java gc 问题

    所以,在第一种情况,请检查您的应用程序日志,如果没有日志,请放置日志并检查您的任何应用程序是否需要时间(日志从不说谎)

    在第二种情况下,检查您的 tomcat 日志,了解那里的状况。

    在第三种情况,请检查您的数据库日志,查询是否需要更多时间。

    第四种情况,你可以监控你的java健康监控,市面上有很多工具如jfr、jcisualvm等..

    另外,您的问题没有足够的解释,请回答以下内容

    1. 您的应用程序的示例结构是什么?
    2. 您如何使应用程序恢复到非正常状态,例如,重新启动是否可以解决您的问题? 我问这个是因为如果您需要重新启动它,那么可能会出现死锁,因此您可能需要使用 jstack 并对其进行分析
    3. 为应用程序分配了多少 XMX?
    4. 您的数据库服务器和应用程序服务器是否在同一台机器上? 因为在某些机器上高峰时间可能会出现一些io问题,所以我们需要检查两者

    请先确定问题出在哪里,然后我们可以进一步,我们如何识别和解决问题。

    谢谢

    【讨论】:

    • 感谢您的回复,我会检查您的建议。提出您的问题:(1)非常简单的 Spring Boot 应用程序,只有 1 个控制器和 6 个方法。为每个用户请求一种方法,如果需要,则为其他方法。 (2) 当活跃用户数量减少时,我什么都不做,一切都按预期工作。 (3) 我没有为应用程序配置它,因此,默认值。我在问题 (4) 中添加了 tomcat 的内存信息,是的,它们在同一台机器上
    • 你好,Javanshir,你完成了我建议的 POA(行动计划)吗,希望你找到了你正在调试的地方。
    • 我做到了,看起来,问题不在于 webapp,而在于 tomcat(或 apache)本身。在高峰时间,即使是我从另一个应用程序(也通过 tomcat)传递的静态页面也会挂起。看起来,与 tomcat 的连接数存在某种限制
    猜你喜欢
    • 1970-01-01
    • 2023-03-20
    • 1970-01-01
    • 2014-03-22
    • 1970-01-01
    • 2017-02-15
    • 2020-07-23
    • 2013-07-11
    • 2014-01-13
    相关资源
    最近更新 更多