起因－日志丢失
生产上出现过几次日志丢失的问题，我们日志每小时生成一个文件，然后每个小时刚到整点切换的时候会生成新文件然后正常输出日志，到了固定时点就空了，只有一个定时清理数据的线程打的几行日志。
通过分析，是因为我们的应用部署在weblogic上，每次重新发war包并不会重启weblogic，只是停止之前的应用，重新启动一个新的，而之前的应用有个别线程没能关闭，与新应用同时打日志，出现了问题。
泄漏的线程与新应用的线程各自持有一个log4j的appender，关键这两个appender的规则完全一致。
新应用的线程一直在打印日志，到了整点就切换，而泄漏的线程每半个小时才被唤醒一次，然后打印几句日志。
我们来看一下log4j切换日志的代码：
|
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
44
45
46
47
48
|
/**
Rollover the current file to a new file.
*/
void rollOver() throws IOException {
/* Compute filename, but only if datePattern is specified */
if (datePattern == null) {
errorHandler.error("Missing DatePattern option in rollOver().");
return;
}
String datedFilename = fileName+sdf.format(now);
// It is too early to roll over because we are still within the
// bounds of the current interval. Rollover will occur once the
// next interval is reached.
if (scheduledFilename.equals(datedFilename)) {
return;
}
// close current file, and rename it to datedFilename
this.closeFile();
//！！！！！！！！！！重点在这！！！！
//如果存在已经重名的就给删掉。
File target = new File(scheduledFilename);
if (target.exists()) {
target.delete();
}
File file = new File(fileName);
boolean result = file.renameTo(target);
if(result) {
LogLog.debug(fileName +" -> "+ scheduledFilename);
} else {
LogLog.error("Failed to rename ["+fileName+"] to ["+scheduledFilename+"].");
}
try {
// This will also close the file. This is OK since multiple
// close operations are safe.
this.setFile(fileName, true, this.bufferedIO, this.bufferSize);
}
catch(IOException e) {
errorHandler.error("setFile("+fileName+", true) call failed.");
}
scheduledFilename = datedFilename;
}
|
假如现在刚到10点了，因为新应用一直在打印日志，10点时切换了一个新日志，然后不停的打日志，结果到了10:15，另一个appender也要打日志了，它发现过了10点了，自己原来持有的日志还是9点点，就切换一个，发现已经有重名点，就删掉重建了，这就是原因。可是有人会说前一个appender持有的文件句柄文件被删了，它不应该报异常吗？经过我的实验，没有任何异常反应。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
|
public static void main(String[] args) throws IOException {
File a = new File("test.txt");
BufferedWriter bw1 = new BufferedWriter(
new FileWriter(a));
bw1.write("aaaaaaaa");
bw1.flush();
a.delete();
bw1.write("aaaaaaaaa");
bw1.flush();
File b = new File("test.txt");
BufferedWriter bw2 = new BufferedWriter(
new FileWriter(b));
bw2.write("bbbbbbbbb");
bw2.flush();
bw1.write("aaaaaaaaa");
bw1.flush();
} |
上面这段代码不会有任何异常，最终生成的文件内容是bbbbbbbbb。
这个问题只是线程泄漏带来的问题之一，还有与之对应的内存泄漏等其它问题。接下来就来分析一下线程泄漏等原因与如何避免此类问题。
应用服务器如何清理线程？
对于应用中自己起动的一些后台线程，应用服务器一般不会给你停掉。不了解weblogic怎么清理这些线程的，看了下tomcat的，tomcat默认并不会强制关闭这些线程。
先看tomcat中的一段警告日志：
七月 27, 2016 7:02:10 下午 org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
警告: The web application [firefly] appears to have started a thread named [memkv-gc-thread-0] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:745)
在tomcat中有关停止这些线程有一个配置默认是关的，如果开了，它是用stop方法，也是有风险的。
|
1
2
3
4
5
6
7
8
9
10
|
/**
* Should Tomcat attempt to terminate threads that have been started by the
* web application? Stopping threads is performed via the deprecated (for
* good reason) <code>Thread.stop()</code> method and is likely to result in
* instability. As such, enabling this should be viewed as an option of last
* resort in a development environment and is not recommended in a
* production environment. If not specified, the default value of
* <code>false</code> will be used.
*/
private boolean clearReferencesStopThreads = false;
|
我猜weblogic也是类似的策略，所以不能指望应用服务器给你清理线程。
应该在什么地方清理线程？
正确的停止应用线程的方法是自己去停止，而不要依赖于应用服务器！
例如，使用spring的，可以利用bean的destroy方法，或者没有spring的，注册一个listener。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
|
public class ContextDestroyListener
implements ServletContextListener {
@Override
public void contextInitialized(ServletContextEvent sce) {
// TODO Auto-generated method stub
}
@Override
public void contextDestroyed(ServletContextEvent sce) {
// TODO Auto-generated method stub
//在这个地方清理线程
}
} |
我们知道在什么地方去清理这些线程了，接下来就是如何去清理他们了。清理线程并不是加个shutdown方法或者调用一下interrupt那么简单的事情。
如何正确停止线程？
要自己停止线程，首先你得拿到线程的句柄，也就是thread对象或者线程池，如果你写了下面的代码，启动完后你就找不到这个线程了，所以线程一定要在清理线程的时候能拿得到句柄。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
|
public static void main(String[] args) {
new Thread(new Runnable() {
@Override
public void run() {
while(true) {
try {
Thread.sleep(1000);
System.out.println("wake up");
} catch (InterruptedException e) {
e.printStackTrace();
}
}
}
}).start();
} |
正确的方法是把Thread放到一个变量里，例如t，然后通过t去停止这个线程。停止线程的方法一般有stop,destroy,interrupt等，但是stop,destroy都已经被废弃了，因为可能造成死锁，所以通常等做法是使用interrupt。使用interrupt其实类似于信号，就好比你在Linux进程中把SIGTERM信号忽略了，那就没法通过kill杀死进程了，interrupt也是如此。 下面等线程只会报一个异常，中断信号被忽略。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
public static void main(String[] args) {
Thread t = new Thread(new Runnable() {
@Override
public void run() {
while(true) {
try {
Thread.sleep(1000);
System.out.println("wake up");
} catch(InterruptedException e) {
e.printStackTrace();
}
}
}
});
t.start();
t.interrupt();//并不能停止线程
} |
这种阻塞的线程，一般调用的函数都会强制检查并抛出interruption异常，类似的还有wait()，阻塞队列的take等，为了程序能正常关闭，InterruptedException最好不好忽略。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
|
public static void main(String[] args) {
Thread t = new Thread(new Runnable() {
@Override
public void run() {
while (true) {
try {
Thread.sleep(1000);
System.out.println("wake up");
} catch (InterruptedException e) {
e.printStackTrace();
System.out.println("stop...");
break;
}
}
}
});
t.start();
t.interrupt();
} |
如果run方法里没有抛出InterruptedException怎么办？例如下面这个
|
1
2
3
4
5
6
7
8
9
10
11
12
13
|
public static void main(String[] args) {
Thread t = new Thread(new Runnable() {
@Override
public void run() {
int i = 0;
while (true) {
i++;
}
}
});
t.start();
t.interrupt();
} |
这种情况就需要run方法里不断检查是否被中断了，否则永远停不下来。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
|
public static void main(String[] args) {
Thread t = new Thread(new Runnable() {
@Override
public void run() {
int i = 0;
while (true) {
i++;
if(Thread.interrupted()) {
System.out.println("stop..");
break;
}
}
}
});
t.start();
t.interrupt();
} |
上面就是正确停止单个线程的方法，对于线程池，一般有两个方法，shutdown和shutdownNow，这两个方法差别是很大的，shutdown只是线程池不再接受新的任务，但是不会打断正在运行的线程，而shutdownNow会对逐个线程调用interrupt方法，如果你的线程是确定可以在一段时间跑完的，可以用shutdown，但是如果是一个死循环，或者在sleep需要很长时间才重新唤醒，那就用shutdownNow，然后对于Runnable的实现也需要遵循上面单个线程的原则。
本文转自nxlhero 51CTO博客，原文链接：http://blog.51cto.com/nxlhero/1905715，如需转载请自行联系原作者