生成thread dump

1

jstack <PID>

查看thread dump文件

1. 保存成xxx.tdump文件,用jvisualvm打开;
2. ✔ 用网站打开: http://spotify.github.io/threaddump-analyzer/
3. 用文本编辑器打开.

其中第二个方法，用网站查看最好用。
此外还可以用另一个网站: http://fastthread.io/
这个网站还能看core dump和hs_err_pid142043.log

jvisualvm查看thread dump

和用文本编辑器的区别只有一个，就是多了语法高亮(字体颜色有区分)。
某个日志如下:

1
2

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

各部分含义:

• 线程名称：Attach Listener
• 线程类型: daemon
• tid: jvm内部线程id;
• nid: 线程id(系统真实)16进制;
• 线程状态: RUNNABLE
• [0x0000000000000000]： 起始栈地址。

案例: 遇到cpu100%的情况

1. 查看某进程下占用高的线程id:
   top –H –p <进程id>
   这里从结果里得到比如 16143 线程id;
2. 查看thread dump:
   jstack -l <进程id>
   上一步的线程id(16143)转换为16进制为0x3f0f,因此在thread dump中看看0x3f0f相关信息即可。（也就是上文中的nid）
   （可以定位到具体是啥线程了）

网站查看thread dump

http://spotify.github.io/threaddump-analyzer
几个改进:

1. 会合并相同栈的线程; (类似一个group by);
2. 会列出锁占用情况(Synchronizers面板);
3. Top Methods From 50 Running Threads。

tip 10进制转16进制

用top -H -p pid找到cpu占用高的线程id(10进制)以后，要去thread dump里找具体是哪个nid(16进制),因此需要用这个linux命令:

1
2

# 把10进制的26转成16进制:
echo 'obase=16;ibase=10;26' | bc

或者用printf:

1
2

printf %x'\n' 26
# 结果是1a

线程状态

• java中的线程状态:
  线程状态转化大致如下:

1. New=>Runnable=>Terminated // 理想状态
2. Runnable => Blocked/Waiting/Time_Waited=>Runnable // 可能误入的歧途

http://xiaoyue26.github.io/2018/02/03/2018-02/java%E5%B9%B6%E5%8F%91%E7%BC%96%E7%A8%8B%E7%9A%84%E8%89%BA%E6%9C%AF-%E7%AC%AC%E5%9B%9B%E7%AB%A0/

• thread dump中的线程状态:
  示例状态与相应线程名:

  1 2 3 4 5 6

  // java.lang.Thread.State: RUNNABLE RUNNABLE: Attach Listener TIMED_WAITING (parking): HikariPool-1 housekeeper TIMED_WAITING (on object monitor): Abandoned connection cleanup thread TIMED_WAITING (sleeping): Hashed wheel timer WAITING (on object monitor): Finalizer

  

状态对应含义详解:

1
2
3

Runnable: 就绪或运行中
Wait on condition: sleeping或者等待事件
Waiting for Monitor Entry and in Object.wait(): 在synchronized,等待对象锁

其中synchronized与obj.wait()这对好基友:
对象锁: 每个对象的临界区Monitor

线程栈示例

1
2
3
4
5
6

"Abandoned connection cleanup thread" #81 daemon prio=5 os_prio=0 tid=0x00007f66acbbc000 nid=0x279b in Object.wait() [0x00007f6646a8b000]
   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 <0x0000000080210720> (a java.lang.ref.ReferenceQueue$Lock)
	at com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)

先lock0x0000000080210720,然后wait.
可以想象代码可能是形如:

1
2
3

synchronized(obj) {  
       obj.wait();  
}

Monitor、Entry Set、Waiting Set

Monitor的两个set: Entry Set, Waiting Set.
首先得进入Entry Set,才能通往Waiting Set，因此要先Synchronized才行。
Entry Set: synchronized
Waiting Set: obj.wait()// syn后。// 会释放对象锁。
唤醒Waiting Set： 在synchronized后调用notify

问题定位

Cpu很忙：检查runnable的线程;

1. 隔一段时间，收集几次thread dump;
2. 比较其中runnable的代码变化。

没变化=>可能在死循环;
有变化=>正常。

Cpu很闲：检查waiting for monitor entry的线程。

1. 隔一段时间，收集几次thread dump;
2. 比较其中waiting for monitor entry的代码变化。

没变化=>可能在死等(死锁); =>可以
有变化=>正常。

Thin Lock, Fat Lock, Spin Lock:

Thin Lock: 某线程通过CAS获得thin lock,其他线程进入spin lock;
fat lock: monitor_enter/monitor_exit，其他线程进入wait(),不消耗cpu;
// 第二个获得锁的人把锁升级成fat lock。// 不能回退/降级

Tasuki锁：（Oracle的BEA JRockit与IBM的JVM）

1. thin lock取消忙等待；
2. fat lock可以回退/降级，通过采样数据分析决定。

查看进程id

首先需要知道我们关心的java程序的进程id，才能方便后续的操作。
jps -lvm
如果不是java程序,则可以用命令ps aux | grep [name]。

查看进程运行参数

jinfo -flags <PID>

查看进程各项统计信息

类加载统计:
jstat -class <PID>
此外还有: 编译统计、垃圾回收统计、堆内存统计、新生代垃圾回收统计、新生代内存统计等等统计信息。
参考: https://www.cnblogs.com/yjd_hycf_space/p/7755633.html
https://blog.csdn.net/zhaozheng7758/article/details/8623549

缺点: 都是文本、英文,不一定马上看得懂。

生成3种dump文件

为了了解更详细进程信息,可以生成3种dump文件:(然后用各种(图形)工具辅助查看)

1. Thread Dump: 线程运行状态;
2. Heap Dump: 堆内存状态;
3. Core Dump: 进程地址空间的内容以及有关进程状态的其他信息写出的一个磁盘文件。

Thread Dump

拿到进程id以后,我们可以用jstack命令生成Thread Dump文件。

1

jstack <PID>

然后可以:

1. 把Thread dump文件装载入jvisualvm查看。
2. 直接文本编辑器打开看;
3. 粘贴到网站,辅助查看: http://spotify.github.io/threaddump-analyzer/

jstack是jvm原生支持的,底层实现原理:

1. tool.jar中提供的一个Attach Listener,监听相关socket连接。
2. sa-jdi.jar中的监听。

Heap Dump

还可以通过jmap命令+进程id，输出Heap Dump。

1

jmap -histo:live <PID>

输出到文件:

1

jmap -dump:live,format=b,file=heap.dump <PID>

需要注意这些指令都可能导致进程挂起,不能频繁在线上环境执行。

得到heap dump文件以后,可以:

1. 用jhat命令: jhat -port 443 [filename],然后访问http://localhost:443查看;
2. 装入到jvisualvm中查看.

参考: http://www.importnew.com/27804.html

Core Dump

还可以输出进程的核心转储文件,方法是对进程发送一些会产生core dump的信号,例如:
kill -3 [PID]
用了上述命令以后core dump数据会输出到进程的标准输出中。（可以事先重定向stdout）

详细的信号包括:

jvisualvm

上述几个工具比较零散,而且大部分是文本,不能直观迅速感知内存是上升还是下降.
可以直接用jvisualvm命令启动图形界面，直接监控本地的java进程(包括堆、thread dump信息等，还能进行操作)。

用法:

1. 监控本地java进程;
2. 装载heap dump,thread dump文件查看;
3. 远端启动jstatd/jmx,打开端口权限,远程监控java程序。

jstatd

准备配置文件:

1

vi jstatd.all.policy

内容如下:

1
2
3

grant codebase "file:/usr/java/default/lib/tools.jar" {   
    permission java.security.AllPermission;   
};

启动:

1

jstatd -J-Djava.security.policy=./jstatd.all.policy

默认会启动在1099端口。
启动以后jvisualvm就能创建远程主机，并监控它所有的java程序了。

jmx

jstatd和jmx似乎不能同时用，不然jvisualvm会卡死.
需要在启动java的时候就指定相应的端口等信息:

1
2
3
4
5
6
7
8
9
10

nohup java \
-Dcom.sun.management.jmxremote=true \
-Dcom.sun.management.jmxremote.port=8080 \
-Dcom.sun.management.jmxremote.ssl=false \
-Dcom.sun.management.jmxremote.authenticate=false \
-Djava.rmi.server.hostname=10.65.89.102 \
-XX:+HeapDumpOnOutOfMemoryError \
-XX:HeapDumpPath=/data/mengqifeng/test \
-classpath pipe-realtime-client-0.0.1-jar-with-dependencies.jar \
com.tencent.kandian.HippoConsumer >> con.log & echo $! > con.pid

然后在jvisualvm中创建远程JMX连接。

jvm启动的几个线程作用:

1. Signal Dispatcher: 接受各种信号;
2. Attach Listener: 监听各种请求的socket连接,把执行的操作扔给VM Thread。
   这里的请求包括:

   1 2 3 4 5 6 7 8 9 10 11 12 13

   static AttachOperationFunctionInfo funcs[] = { { "agentProperties", get_agent_properties }, { "datadump", data_dump }, { "dumpheap", dump_heap }, { "load", JvmtiExport::load_agent_library }, { "properties", get_system_properties }, { "threaddump", thread_dump }, { "inspectheap", heap_inspection }, { "setflag", set_flag }, { "printflag", print_flag }, { "jcmd", jcmd }, { NULL, NULL } };

3. VM Thread: 线程母体,最原始的线程,单例,里面有个队列，存放上面的操作,它负责loop处理队列中的操作.（包括对其他线程的创建，分配和对象的清理，cms-mark等工作）
4. CompilerThread0: JIT动态编译线程;
5. ConcurrentMark-SweepGCThread: CMS垃圾收集线程;
6. DestroyJavaVM: 负责卸载JVM的线程;
7. ContainerBackground Processor: JBoss守护线程;
8. Dispatcher-Thread-3: Log4j异步日志守护线程;
9. Finalizer: 垃圾回收守护线程;
10. Gang worker#0: 新生代回收线程;
11. GC Daemon: RMI远程GC线程(调用system.gc());
12. Low MemoryDetector: 发现可用内存低，则分配新的内存空间;
13. process reaper: 执行os命令;
14. Reference Handler: 处理引用对象本身（软、弱、虚引用）的垃圾回收问题;
15. SurrogateLockerThread: CMS垃圾回收;
16. VM Periodic Task Thread: 定期的内存监控、JVM运行状况监控。

参考: http://ifeve.com/jvm-thread/

示例1:sparkstreaming的driver配置

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

-Djava.library.path=$JAVA_LIBRARY_PATH:/data/gaiaadmin/gaiaenv/tdwgaia/lib/native
-verbose:gc
-XX:-PrintGCDetails 
-XX:+PrintGCDateStamps
-Xloggc:<LOG_DIR>/gc.log
-XX:MaxPermSize=256m 
-XX:SurvivorRatio=4 
-XX:+UseMembar 
-XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled 
-XX:+CMSScavengeBeforeRemark 
-XX:ParallelCMSThreads=4 
-XX:+UseCMSCompactAtFullCollection 
-XX:+CMSClassUnloadingEnabled 
-XX:CMSInitiatingOccupancyFraction=50 
-XX:+UseCompressedOops

含义:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

-verbose:gc是官方推荐配置,等效于-XX:+PrintGC,表示打印gc日志;
-XX:-PrintGCDetails 减号,关闭详细gc日志;
-XX:+PrintGCDateStamps  加号,打开gc日志日期;
-Xloggc:<LOG_DIR>/gc.log 指定gc日志路径;
-XX:MaxPermSize=256m  最大永生代大小;
-XX:SurvivorRatio=4  两个survivor:新生代的比例;
8的话: 2:8,每个survivor占1/10;
4的话: 2:4,每个survivor占1/6;
-XX:+UseMembar 使用真内存屏障
-XX:+UseConcMarkSweepGC 使用ParNew & CMS（serial old为替补）搜集器
-XX:+CMSParallelRemarkEnabled CMS第二次标记,使用并发标记
-XX:+CMSScavengeBeforeRemark 第二次标记前进行一次minorGC
-XX:ParallelCMSThreads=4 回收线程数
-XX:+UseCMSCompactAtFullCollection 防止堆碎片引起full gc,开启CMS阶段进行合并碎片选项
-XX:+CMSClassUnloadingEnabled 开启回收Perm永生代
-XX:CMSInitiatingOccupancyFraction=50 在老生代占满50%的时候开始回收
-XX:+UseCompressedOops 压缩指针(64位有效)

示例2:某spring boot进程jvm非默认配置

jinfo -flags PID结果:

1
2
3
4
5
6
7
8
9
10
11

Non-default VM flags: 
-XX:CICompilerCount=15 
-XX:InitialHeapSize=2107637760 
-XX:MaxHeapSize=32210157568 
-XX:MaxNewSize=10736369664 
-XX:MinHeapDeltaBytes=524288 
-XX:NewSize=702545920 
-XX:OldSize=1405091840 
-XX:+UseCompressedClassPointers 
-XX:+UseCompressedOops 
-XX:+UseParallelGC

含义:

1
2
3
4
5
6
7
8
9
10

-XX:CICompilerCount=15 JIT的编译线程数
-XX:InitialHeapSize=2107637760  初始堆大小
-XX:MaxHeapSize=32210157568     最大堆大小
-XX:NewSize=702545920        新生代初始大小
-XX:MaxNewSize=10736369664   新生代最大大小
-XX:MinHeapDeltaBytes=524288 每次扩展堆的时候最小增长
-XX:OldSize=1405091840       老生代初始大小
-XX:+UseCompressedClassPointers 压缩指针
-XX:+UseCompressedOops          压缩优化
-XX:+UseParallelGC           Parallel Scavenge + Serial Old 吞吐率优先

jvm配置

参考https://www.cnblogs.com/z-sm/p/6253335.html

分类

-X: 稳定选项;
-XX: 非标准选项;

查看运行的java程序的启动命令

jps -lvm

运行时查看JVM配置

语法如下:
jinfo -flag <name> PID
如:
jinfo -flag CMSAbortablePrecleanWaitMillis 11715

查看全部非默认配置:
jinfo -flags PID
或者:
jcmd PID VM.flags

运行时修改JVM配置

首先并不是所有JVM配置都能在运行时动态修改的,需要查看哪些配置是可以运行时动态修改的:

列出可运行时调整的JVM配置(linux)

java -XX:+PrintFlagsInitial | grep manageable
结果如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18

intx CMSAbortablePrecleanWaitMillis = 100 {manageable}
intx CMSTriggerInterval  = -1 {manageable}
intx CMSWaitDuration = 2000 {manageable}
bool HeapDumpAfterFullGC = false {manageable}
bool HeapDumpBeforeFullGC   = false {manageable}
bool HeapDumpOnOutOfMemoryError  = false {manageable}
ccstr HeapDumpPath = {manageable}
uintx MaxHeapFreeRatio = 70 {manageable}
uintx MinHeapFreeRatio = 40 {manageable}
bool PrintClassHistogram = false {manageable}
bool PrintClassHistogramAfterFullGC = false {manageable}
bool PrintClassHistogramBeforeFullGC  = false {manageable}
bool PrintConcurrentLocks   = false {manageable}
bool PrintGC  = false {manageable}
bool PrintGCDateStamps   = false {manageable}
bool PrintGCDetails   = false {manageable}
bool PrintGCID = false {manageable}
bool PrintGCTimeStamps   = false {manageable}

可以看到参数的类型主要分为bool和非bool(intx,uintx,ccstr)。

运行时修改bool型配置

用加减(+/-)表示开关:
jinfo -flag [+|-]<name> PID

运行时修改intx/ccstr/uintx型配置

jinfo -flag <name>=<value> PID

示例

比如我们有一个java进程11715,我们突然想查看它的gc情况,但是之前又没有打开gc日志,只重定向了控制台日志,这个时候可以动态打开:

1
2
3

jinfo -flag +PrintGC 11715
jinfo -flag +PrintGCDateStamps 11715
jinfo -flag +PrintGCDetails 11715

拿到日志:

1

2018-11-25T20:21:41.772+0800: [GC (Allocation Failure) [PSYoungGen: 45952K->1856K(48128K)] 248269K->204197K(309248K), 0.0423007 secs] [Times: user=0.88 sys=0.02, real=0.06 secs]

调试完后再关掉即可:

1
2
3

jinfo -flag -PrintGC 11715
jinfo -flag -PrintGCDateStamps 11715
jinfo -flag -PrintGCDetails 11715

gc日志示例

1
2
3
4
5
6
7
8
9
10

2018-11-11T17:53:47.765+0800: 6.223: [GC (CMS Initial Mark)  1208720K(9946240K), 0.0293534 secs]
2018-11-11T17:53:48.622+0800: 7.080: [GC (Allocation Failure)  2158400K->38812K(9946240K), 0.0383138 secs]
2018-11-11T17:53:51.479+0800: 9.937: [GC (CMS Final Remark) 2018-11-11T17:53:51.480+0800: 9.937: [GC (CMS Final Remark)  1167518K->22899K(9946240K), 0.0147020 secs]
 22899K(9946240K), 0.0299512 secs]
2018-11-11T17:53:55.022+0800: 13.480: [GC (Allocation Failure)  2176846K->89359K(9946240K), 0.0181967 secs]
2018-11-11T17:54:08.938+0800: 27.396: [GC (Allocation Failure)  2247759K->301630K(9946240K), 0.1307113 secs]
2018-11-11T17:54:12.721+0800: 31.179: [GC (Allocation Failure)  2460030K->337872K(9946240K), 0.6716872 secs]
2018-11-11T17:54:14.953+0800: 33.411: [GC (Allocation Failure)  2496272K->338204K(9946240K), 0.1792878 secs]
2018-11-11T17:54:15.133+0800: 33.591: [GC (GCLocker Initiated GC)  362412K->368987K(9946240K), 0.0447314 secs]
2018-11-11T17:54:48.328+0800: 66.786: [GC (Allocation Failure)  2527387K->347750K(9946240K), 0.0532146 secs]

gc日志的组成

1. 日期时间: 2018-11-11T17:53:47.765+0800:;
2. jvm启动依赖的时间(秒): 6.223:;
3. GC停顿类型: [GC (CMS Initial Mark);
4. (不一定有)GC发生区域: [DefNew”、“[Tenured”、“[Perm;
5. (不一定有,针对4中的区域)GC前后该容量变化:
   GC前该内存区域已使用容量-＞GC后该内存区域已使用容量（该内存区域总容量）
   2496272K->338204K(9946240K);
6. GC前后java堆容量变化:
   GC前Java堆已使用容量-＞GC后Java堆已使用容量（Java堆总容量）
   3324K-＞152K（11904K）;
7. GC耗时: 0.0383138 secs.

GC区域

1. New: 新生代、年轻代;
2. Tenured: 老生代、老年代;
3. Perm: 永久代.

收集器的类型+区域: DefNew: Default Serial收集器的新生代区域。

目标

消除全部FullGC,普通gc时间占用少于5%。
网上说少于3秒一次的频率,由于我们是离线应用,目前还没有什么思路能达到这种性能。

需求:

有大量定时任务需要执行，精度要求不高，可以允许延迟执行。
可能的场景: 每个连接的超时事件、每个请求的超时事件。

方案1:

每个定时任务设置一个定时器、或一个Scheduled,DelayedQueue和实现Delayed接口的线程。
缺点: 开销太大;
优点: 少量任务时精度较高。

方案2: 超时集

将相同时间间隔的任务组织成一个集合。每个集合分配一个计时器（thread）。
缺点: 相同时间间隔难以满足，性能不够。

方案3: HashedWheelTimer： 时间轮算法(Netty4工具类)

设计一个虚拟的哈希表组织定时任务。
优点: 默认只用一个thread,开销小;
缺点:

1. 精度降低到tickDuration粒度;
2. 定时任务不能太耗时;(解决方案: 可以在定时任务里异步处理)。

基本架构

如上图所示即为时间轮。
引入术语:

1
2
3
4

tick: 时间轮里每一格;
tickDuration: 每一格的时长;
ticksPerWheel: 时间轮总共有多少格.
newTimeout: 定时任务分配到时间轮

定时任务分配到时间轮

分配流程:

1. 计算定时任务deadline = System.nanoTime() + unit.toNanos(delay) - startTime;
2. 计算定时任务放入第几格:

   1 2 3

   long calculated = deadline / tickDuration; // 需要计算几次 final long ticks(还需要走几格) = Math.max(calculated, 当前tick次数); // 一般就等于calculated，这里只是为了确保不在以前走过的格子里（这样的话这个任务永远不会执行而且移除不掉了） stopIndex = (int) (ticks & mask); // 相当于% wheel.length，因为长度是2的幂。

3. 计算定时任务第几轮被调用: remainingRounds = (calculated - tick) / wheel.length;
4. 放入时间轮stopIndex位置中任务链表: (remainingRounds,task)：

   1 2	HashedWheelBucket bucket = wheel[stopIndex]; bucket.addTimeout(timeout); // 加入链表尾部。

当这个时间轮开始运行的时候（也就是开始计时，执行定时任务了），每次跳转一个tick,都会检查这个tick里的定时任务,如果定时任务轮次应当执行，则执行对应任务。

使用的示例代码:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43

/**
 * tickDuration: 每 tick 一次的时间间隔, 每 tick 一次就会到达下一个槽位
 * ticksPerWheel: 轮中的 slot 数
 */
@Test
public void testHashedWheelTimer() throws InterruptedException {
// 1000ms一格,一轮16格（一般是2的N次幂，这样可以把hash转换为&0xFFFF）
    HashedWheelTimer hashedWheelTimer = new HashedWheelTimer(1000,TimeUnit.MILLISECONDS, 16 );
    System.out.println(LocalTime.now()+" submitted");
    Timeout timeout = hashedWheelTimer.newTimeout((t) -> {
        new Thread(){
            @Override
            public void run() {
                System.out.println(new Date() + " executed");
                System.out.println(hashedWheelTimer);
                try {
                    TimeUnit.SECONDS.sleep(100);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                System.out.println(new Date() + " FINISH");
            }
        }.start();
    }, 5, TimeUnit.SECONDS);

    hashedWheelTimer.newTimeout((t) -> {
        new Thread(){
            @Override
            public void run() {
                System.out.println(new Date() + " TASK2 executed");
                System.out.println(hashedWheelTimer);
                try {
                    TimeUnit.SECONDS.sleep(10);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                System.out.println(new Date() + " TASK2 FINISH");
            }
        }.start();
    }, 15, TimeUnit.SECONDS);

    TimeUnit.SECONDS.sleep(500);
}

HashedWheelTimer源码:
https://github.com/netty/netty/blob/4.1/common/src/main/java/io/netty/util/HashedWheelTimer.java

理论基础:(操作系统内核的定时器)
http://www.cs.columbia.edu/~nahum/w6998/papers/sosp87-timing-wheels.pdf

方案4： 层级时间轮(Kafka使用)

上述简单时间轮的算法存在的缺点:
对于延迟很长时间的任务,该方案存在较多的cpu空转。一种可能的方案是增大tickduration,但是很难兼顾精度和性能。

一种解决方案: 层级时间轮。
思路是模拟现实中的钟表,现实中的钟表有时针、分针、秒针,相当于不同tickDuration的时间轮。
架构图如下:

不同于Netty4中每个任务存放自己应到执行的轮次,层级时间轮把高轮次的定时任务分配到高层的时间轮中:层数越高=>tickDuration越大。

假如定义最低层的时间轮的层号为0,高一层的为1,依次类推,只有n-1层的定时任务到期后,才会取出n层时间轮的定时任务处理（要么直接执行,要么降级,要么放回时间轮）。

(如果让层级时间轮每层的tickDuratino相同，则退化为方案3的普通时间轮。)

同时为了辅助推进时间轮的指针,使用DelayQueue存放最近到期的定时任务

双向链表

时间中每一个格中使用的数据结构为双向链表。
好处是只要持有其中某个节点，就可以在O(1)时间内进行插入或者删除操作。

到期操作

由DelayQueue辅助推进指针:

1. DelayQueue中优先级队列的队首最近到期的定时任务。处理结束后,由leader线程等待下一个定时任务的时间。因此推进步长由定时任务的间隔决定,没有cpu空转的现象。
2. 推进所有时间轮的指针,对于遇到的定时任务,要么插入低层时间轮,要么删除(执行)。

插入操作(删除类似)

插入新的定时任务:

1. 插入时间轮: 根据到期时间,可以算出具体应该放在哪一层时间轮的哪一格,得到对应的双向链表引用。如果这一格还是空的,需要新建一个,然后插入到DelayQueue中(O(logN)时间复杂度)。(参见DelayQueue原理,如果时间低于DelayQueue的最小延时任务,会提前唤醒里面的leader线程)
2. 插入DelayQueue: 根据上一步中得到的双向链表引用,往里面插入新的定时任务（O(1)）。

总结

层级时间轮通过不同tickDuration的时间轮,以较小的空间映射到一个很大的时间范围,兼顾了精度和性能。
插入删除的时间复杂度:
时间复杂度其实取决于有效格子的数量,因为DelayQueue存放的是有任务的格子,也就是双向链表的数量。低层用的是优先级队列(最小堆),假如有效格子的数量是m，则复杂度为O(log(m))。
实际中m一般远小于n，因此性能有很大的提高。
理想情况:定时任务的时间间隔分布能尽量让它们位于相同格子中。 (O(1))
最坏情况:所有双向链表都只有一个任务(均匀地分布在不同格子中)。(O(logN))

实际业务中,定时任务一般都服从对数正态分布,因此每次插入删除时间复杂度是接近O(1)的。

DelayQueue: JDK提供的延迟获取元素的无界阻塞队列。
应用场景:

1. 缓存有效期: 能取到的时候过期.
2. 定时任务: 能取到的时候执行。

DelayQueue的两个特性:
无界: 说明底层至少使用了链表。
阻塞: 为底层实现时，利用访问线程干活埋下伏笔(leader)。

底层实现机制

底层用一个优先级队列存储delay元素(比如定时任务),排序依据是延迟的时长。
可以看出，这里用的是一个支持无界阻塞的优先级队列实现(例如PriorityBlockingQueue)。

时间复杂度: O(logN)。由于使用的是优先级队列(最小堆),插入新元素(任务)的时间复杂度是O(logN)。

take流程:

1. lock.lockInterruptibly();
2. delay = 队首元素延时;
3. delay<=0: 取出该元素;
4. delay>0: 尝试设置自己线程为leader，然后等待delay时间。
5. finnally: lock.unlock();

这里leader的职责是等待delay时间，以及唤醒其他等待线程。
注意第四步里, 由于leader只能有一个,所以如果尝试成为leader失败，就直接await就好,会被leader叫醒的。

offer: offer就是简单地把元素插入堆中。如果正好是延迟最小，则此时之前的leader等待时间太长了，因此需要叫醒所有等待线程。

总结

DelayQueue
优点:
资源开销小: 本质上只需一个线程负责等待;每次等待间隔都是delay时间,cpu空转少。
缺点
插入删除延时元素时间复杂度为O(logN)，对于成千上万的延时任务时间开销大,有待优化。

优化思路:
如果要比O(logN)更好,很自然的思路就是使用哈希表O(1)，空间换时间。

优化方案

需求: 降低插入删除延时元素的时间复杂度。
方案:

1. 保留优先级队列,但里面的元素改成链表引用(比如从Task到List<Task>);
2. 引入辅助哈希表,保存的也是链表引用(List<Task>)，hash函数的输入为延时时长。

这里即使List<Task>长期只有1个元素也没有关系,这里只是为了起到C++中指针的效果，方便从哈希表里直接修改(插入删除)优先级队里的数据。

take/offer流程: 与之前相似,唯一不同就是取到List<Task>后，遍历其中所有Task。

插入延时元素(任务)：（删除也类似）

1. 根据延时,通过哈希函数找到哈希表中的槽位;
2. 如果以前有过相同延时: 直接插入List;
3. 如果以前没有相同延时: 新建List，并且插入优先级队列。

可以看出这里优化的重要条件是能合并多个Task到List。
为了达到这个条件，可以使用进一步的优化方案: 时间轮。

架构图

如图所示，底层使用mysql，web服务使用flask-SqlAlchemy的连接池（复用连接，减少创建销毁开销），逻辑层代码使用线程池（异步IO操作，如果要异步cpu操作，可以很方便改成进程池）。

基础知识

1. 使用db.engine.execute(sql): 从连接池获取一个连接,执行完sql后自动commit;(commit操作的回调是: 归还连接到池里);
2. 使用session的orm(xxxModel.query等): 默认配置及推荐配置是autocommit=false，执行完增删查改后，处于事务未提交的状态，也就是没有归还连接。如果要归还连接，可以使用语句:

   1 2 3 4

   db.session.commit() db.session.rollback() db.session.close() db.session.remove(): 底层会调用db.session.close()

小结:

db.engine.execute(sql) => 自动commit => 自动归还
session(orm) => 手动commit => 手动归还
因此db.engine.execute(sql)是绝对安全的;
orm是有条件的。接着往下看orm的安全条件。

线程与session

使用flask的SqlAlchemy插件flask-SqlAlchemy时，每个线程可以直接用db.session获得session，即使不显式获得，使用orm的model时，其实也隐式得获得了session。

线程与session的关系:

每个线程有自己的threadlocal的session对象，并且随着线程销毁，会自动释放session,也就是会隐式调用session.remove，也就是会隐式释放session的连接。

多线程两种使用:

1. t1=threading.Thread(...);
2. 线程池: future= pool.submit(...).
   方法1的线程使用完以后自动销毁=>session自动销毁=>连接自动释放;
   方法2的线程使用完以后归还线程池=>session手动销毁=>连接释放。

小结:
不使用线程池=>连接自动释放;
使用线程池=>连接手动释放.
手动释放的方法:

1

db.session.remove()

空闲连接超时与连接释放bug

前面说到使用线程池时，连接没有自动释放，一直维护在线程的threadlocal存储中(tls)。那么这样似乎也没有什么关系，只要线程池大小<连接池大小,这样连接池有空闲连接，每个线程也有自己的连接可以用，一切似乎也相安无事。

然而，这里有一个之前没有提到的机制：空闲连接超时回收。

空闲连接超时回收

mysql服务端:

定期检查现存连接的空闲时间，把超出wait_timeout的连接删除，此时客户端保存的长连接引用就失效了; 这个时间的设定:

1
2

show global variables like 'wait_timeout';
set global wait_timeout=10*60; -- seconds

web服务:

flask会定期检查连接池里的连接，把空闲连接删除，重新向mysql服务端申请新的连接，这样就不会访问到失效的连接引用了。其中定期的时间是: app.config['SQLALCHEMY_POOL_RECYCLE'] =xxx(秒，应当设置为小于wait_timeout)。这就是为什么最好连接用完及时归还，否则可能就没法被flask刷新成新连接。

空闲连接超时与连接释放bug

bug发生的流程

1. mysql服务端清除了空闲时间过长的连接;
2. 线程池中线程一直不销毁，因此持有了活了很久的session;
3. 活了很久的session持有了空闲很久的连接, 这个连接其实已经被服务端销毁了，因此已经不可用了，但是由于其一直没有归还到连接池中，因此一直没有得到更新。
4. 此时web服务收到数据请求，使用该线程中的该session中的连接，就会抛异常了，因为连接已经不可用了。

一般来说，空闲时间很长以后，线程池里所有线程的所有session的所有连接都会失效，因此就会完全无法通过orm访问数据库了。

相关异常信息:

1
2

MySQL server has gone away
Can't reconnect until invalid transaction is rolled back

这里之所以说invalid transaction is rolled back，是因为老session收到数据请求后，准备要用连接了。
而连接上的事务没有自动提交，也没有rollback，因此不能直接用。
因此尝试把连接上，上一次请求的事务提交，但由于连接已经失效，所以失败了。

反直觉优化

慢查询:

1
2
3
4
5
6

select *
    from layer_data.layers_push b
    where group_key='nopushtest'
    AND utype='10w1'
    AND dt>=20180620 AND dt<=20181020
    AND bucket_id=60

上述SQL执行时间约在2.10秒,通过查看执行计划,可以发现有一个异常的指标,预估扫描的行数(rows)为96W，而实际结果行数应该在几十条。(查询涉及到的列合起来是联合主键)
此外type为range，执行的是范围扫描。
查询计划:(explain exntended select ...)

1
2
3
4
5

+----+-------------+-------------+-------+---------------+---------+---------+------+--------+-------------+
| id | select_type | table       | type  | possible_keys | key     | key_len | ref  | rows   | Extra       |
+----+-------------+-------------+-------+---------------+---------+---------+------+--------+-------------+
|  1 | SIMPLE      | layers_push | range | PRIMARY       | PRIMARY | 216     | NULL | 989236 | Using where |
+----+-------------+-------------+-------+---------------+---------+---------+------+--------+-------------+

快查询:（反直觉优化）

基于上面观察到预估行数异常，一个自然的思路就是引入一个很小的辅助表来帮助优化器减少扫描的行数。辅助表的主键与原表分布相同:

1
2
3
4
5
6
7
8
9
10
11

select b.*
from layer_data.layers__nopushtest a
join layer_data.layers_push b
 ON a.dt=b.dt
AND a.bucket_id=b.bucket_id
AND b.group_key='nopushtest'
AND b.dt between 20180620 AND 20181020
AND b.utype='10w1'
    where a.dt>=20180620 and a.dt<=20181020
    and a.utype='w1'
    and a.bucket_id=60

优化后,执行时间大约在0.05秒,快了40多倍。
优化后的执行计划:

1
2
3
4
5
6

+----+-------------+-------+--------+---------------+---------+---------+-----------------------------------+-------+--------------------------+
| id | select_type | table | type   | possible_keys | key     | key_len | ref                               | rows  | Extra                    |
+----+-------------+-------+--------+---------------+---------+---------+-----------------------------------+-------+--------------------------+
|  1 | SIMPLE      | a     | range  | PRIMARY       | PRIMARY | 38      | NULL                              | 23925 | Using where; Using index |
|  1 | SIMPLE      | b     | eq_ref | PRIMARY       | PRIMARY | 216     | layer_data.a.dt,const,const,const |     1 | Using where              |
+----+-------------+-------+--------+---------------+---------+---------+-----------------------------------+-------+--------------------------+

执行流程:
第一步:范围扫描表a,得到连接键的所有可能取值;
第二步: 表b的type是eq_ref(等值连接,而且是唯一键),ref是layer_data.a.dt,const,const,const，预估扫描的行数变成只有1。

原理分析

慢查询的执行计划:

预估的行数有96w，执行计划是从dt为20180620的数据页顺序扫描到dt为20181020的数据页。

范围查询的扫描行数预估：

这里由于使用的mysql版本是5.6(可以通过select version();语句查看)，预估的流程:

1. 取符合where条件的最左边的数据页及后续的8个页，再加上符合where条件的最右边的数据页,共计10个页进行采样;
2. 根据上述采样结果，以及与总数据的采样比，估算出需要扫描的行数。

快查询的执行计划:

因为有辅助的小表帮忙，扫描的行数减少。执行计划是先范围扫描小表，得到所有连接键的取值后，用表b的索引挨个儿进行点查询（type是eq_ref，而不是range）,扫描的数据页大大减少。

range类型查询:

以下操作符会导致查询计划为range:
=, <>, >, >=, <, <=, IS NULL, <=>, BETWEEN, IN (…)

符合直觉的优化

由于mysql对in有特殊的优化: 把范围查询转换为多次点查询。
此时虽然查询计划是range，但实际执行时候不会进行范围扫描，而会进行点查询。
因此也可以把查询改写成:

1
2
3
4
5
6
7
8

select   *
    from layer_data.layers_push b
    where group_key='nopushtest'
    AND utype='10w1'
    AND dt  in  (20180805,20180806,20180807,20180808,20180809,20180810,20180811,20180812,20180813,20180814,20180815,20180816,20180817,20180818,20180819,20180820,20180821,20180822,20180823,20180824,20180825,20180826,20180827,20180828,20180829,20180830,20180831
,20180901,20180902,20180903,20180904,20180905,20180906,20180907,20180908,20180909,20180910,20180911,20180912,20180913,20180914,20180915,20180916,20180917,20180918,20180919,20180920,20180921,20180922,20180923,20180924,20180925,20180926,20180927,20180928,20180929,20180930
,20181001,20181002,20181003,20181004,20181005,20181006,20181007,20181008,20181009,20181010,20181011,20181012,20181013,20181014,20181015,20181016,20181017,20181018,20181019,20181020,20181021,20181022,20181023,20181024,20181025,20181026,20181027)
    AND bucket_id=60

优点:
直观,速度最快。
缺点:
啰嗦，改写起来比较麻烦，只适用于能使用代码预处理sql的地方，而且有最大长度限制。

in查询的扫描行数预估

有两种方式:

1. 精确计算(index_dive): 直接查询对应的行;
2. 采样预估(index statistics): 采样10个数据页,通过索引的选择性统计数据，预估总行数。

具体采取哪种方式，由eq_range_index_dive_limit参数控制(默认是10)。
小于eq_range_index_dive_limit的时候，采用方法1，精确计算；
大于等于eq_range_index_dive_limit的时候，采用方法2, 采样预估。

执行计划耗时

可以通过命令查看某个查询的具体耗时及具体发生了哪些操作:

1
2
3
4
5

set profiling=1;
-- select * from xxx ;
show profiles;
show profile for query 1;
show profile all for query 1; -- cpu,io等详细信息

这里可以看到之前的慢查询发生了51w个block io input。

优化器查询计划选择

可以通过命令查看某个查询生成执行计划时，考虑过哪些方案，以及对于where条件的等价变换，最终选择了哪个方案(chosen:true)。

1
2
3
4

set optimizer_trace="enabled=on";
SET optimizer_trace_max_mem_size=1000000;
explain select xxx
select * from information_schema.OPTIMIZER_TRACE\G

可以看到对于之前慢查询的查询条件只用到了dt条件，其他where条件是在服务器层进行过滤的。