android异常退出销毁线程,在学习android_serialport_api的例程时遇到的接收线程没有正常退出的问题和解决过程...

问题背景

在实现android_serialport_api的sample/LoopBackActivity例程的时候，意外发现一个奇怪的现象：有时候启动LoopBackActivity时，第一个字节会Lost(Corrupted为0)。进入调试模式，断点打在接收线程的onDataReceived()里，发现确实有收到第一个值为"0"的字节，并且用示波器抓波形，第一个字节也确实发出了。那么是什么原因造成的呢？

中间猜想

调试发现收到第一个字节时，接收线程里的mValueToSend(即当前发送字符)不是0(且mOutGoing和mInComing都不是0)，而是一个-127~128的一个“随机值”(每次Lost时该值都不一样)，更奇怪的是接收线程里mCorrupted确实加1了，但是到了发送线程里mCorrupted又变成了0(mOutGoing和mInComing也都是0，只有mLost加1)。这个现象让我不免觉得是两个线程对变量的读取不一致造成的，于是上网查资料得知java线程确实可能有这个问题：java多线程解读二(内存篇)

Java内存模型中规定了所有的变量都存储在主内存中，每条线程还有自己的虚拟内存。线程的虚拟内存中保存了该线程使用到的变量到主内存副本拷贝。线程对变量的所有操作(读取、赋值)都必须在自己的虚拟内存中进行，而不能直接读写主内存中的变量。不同线程之间无法直接访问对方虚拟内存中的变量，线程间变量值的传递均需要在主内存来完成。

如何避免多线程对变量访问的不同步，java 中如何避免多线程不安全 里面说到可以使用volatile或同步锁：

使用volatile变量

volatile变量内存语义

1.当对一个volatile变量进行写操作的时候，JMM会把该线程对应的本地内存中的共享变量的值刷新到主内存中。

2.当一个线程读volatile变量时，JMM会把该线程对应的本地内存变量置为无效，要求线程从主内存中读该变量。

使用锁(synchronized,可重入锁)

锁的内存语义：

1.当线程释放锁时，JMM会把该线程对应的本地内存中的共享变量刷新到主内存中。

2.当线程获取锁时，JMM会把当前线程拥有的本地内存共享变量置为无效，线程从主内存中读取共享变量。

但是程序里本来就使用了synchronized关键字来进行接收线程和发送线程的同步，应该是不会有这个问题的，但是不放心我又在共享变量前加了volatile关键字，结果不出意料的还是会出现第一个字节lost的问题。说明不是这个原因造成的。继续寻找原因。

问题症结

仔细观察调试信息，神奇地发现接收线程和发送线程加锁的对mByteReceivedBackSemaphore居然不是同一个(地址不同)！进而发现两个线程所属于的activity都不是一个实例！于是有一个大胆的猜测：出问题的接收线程所属的activity会不会是上一次返回的activity! 两次打开观察调试信息，真的是这样！如下：

第一个字节“lost”的SendingThread所属的activity，看到所有变量都是"0"

收到第一个字节的onDataReceived()(在mReadThread中调用)所属的activity,看到mInComing并不是"0"

两个不属于同一个activity，synchronized的对象mByteReceivedBackSemaphore当然也不一样！

然后运行一段时间后，再在onDataReceived()中暂停却发现activity和SendingThread一样了。

关闭后再打开一次，再次出现第一个字节"lost"的问题，此时接收线程所属于的activity:

果然和第一次的发送线程的activity是同一个！！原因找到了，两个activity实例，当然变量都不一样，mValueToSend的奇怪“随机值”其实是上一个activity发送的最后一个字符。

虽然致病因子找到了，但是紧接着问题就来了：明明按下返回键销毁了活动，为什么接收线程却苟活了下来？而且在销毁活动时明明都关闭了串口，怎么它的InputStream还能接收？

在网上查找线程没有正常退出的原因，得知关闭线程通常有两种：

1、 在线程中加入一个成员变量，当一个flag使用。在线程run()方法中轮流去检查这个变量，变量变化时就退出这个线程。

2、 第一个方法虽然可以处理好，不过，在有阻塞线程的语句的时候往往不能处理好，因为线程被阻塞了(比如调用wait(), sleep(), join()三个方法之一)，它便不能核查成员变量，就不能停止。这个时候可以使用thread.interrupt()方法。Interrupt()方法只能解决抛出InterruptedException异常的阻塞。

那么遇到一些其他的io阻塞怎么处理呢？有些IO接口也是可以被interrpted的(指能够抛出CloseByInterruptException的IO Operation)。

关于interrupt()：

public void interrupt ()

Added in API level 1

Posts an interrupt request to this Thread. The behavior depends on the state of this Thread:

Threads blocked in one of Object's wait() methods or one of Thread's join() or sleep() >methods will be woken up, their interrupt status will be cleared, and they receive an >InterruptedException.

Threads blocked in an I/O operation of an InterruptibleChannel will have their interrupt >status set and receive an ClosedByInterruptException. Also, the channel will be closed.

Threads blocked in a Selector will have their interrupt status set and return immediately. They don't receive an exception in this case.

See Also

interrupted()

isInterrupted()

一开始读这些内容，我并没有获取到什么有帮助的信息，因为在onDestroy()时已经调用了mReadThread.interrupt()，按理说mReadThread在检测到它的interrupt标志应该就能及时退出呀。如下：

private class ReadThread extends Thread {

@Override

public void run() {

super.run();

byte[] buffer = new byte[64];

int size;

while(!isInterrupted()) {

try {

if (mInputStream == null) return;

size = mInputStream.read(buffer);

if (size > 0) {

onDataReceived(buffer, size);

}

} catch (IOException e) {

e.printStackTrace();

return;

}

}

Log.d(TAG, "mReadThread quits while at" + System.currentTimeMillis());

}

}

在反复看这些文字后，我突然对“io阻塞”来了灵感，这才意识到，串口的InputStream.read()方法就是io操作呀，并且还会阻塞呀！

public abstract int read ()

Added in API level 1

Reads a single byte from this stream and returns it as an integer in the range from 0 to 255. Returns -1 if the end of the stream has been reached. Blocks until one byte has been read, the end of the source stream is detected or an exception is thrown.

Throws

IOException

if the stream is closed or another IOException occurs.

public int read (byte[] buffer, int byteOffset, int byteCount)

Added in API level 1

Reads up to byteCount bytes from this stream and stores them in the byte array buffer starting at byteOffset. Returns the number of bytes actually read or -1 if the end of the stream has been reached.

Throws

IndexOutOfBoundsException

if byteOffset < 0 || byteCount < 0 || byteOffset + byteCount > buffer.length.

IOException

if the stream is closed or another IOException occurs.

即没有字节就会一直block，有数据就会返回接收到的实际字节数量。

于是乎我茅塞顿开：

1)接收线程之所于没有及时退出，正是因为SendingThread退出后，没有字节流进来，mReadThread就一直卡在read()方法，根本没办法去检查isInterrupt().

2)串口虽然关闭，但是关闭串口前，接收线程就已经运行到了mInputStream.read(buffer)，并且阻塞在这，也就是说接收通道一直存在，一旦有一个字符进来，当然是能读到。

3)下一次启动活动时打开的SendgingThread发送的第一个字节就被这个mReadThread残留的接收通道抓到了，然后它检查while()条件发现isInterrupted()成立，这才退出历史舞台。后面的字节都被新活动的mReadThread正常获取。所以后面再在onDataReceived()中暂停就发现activity和SendingThread的activity一样了。

4)有时候又可以正常退出的原因是，SendingThread在sleep()时抛出InterruptException清除了interrupt标志，因此并没有立即退出while循环，继续发出一个字符，此时串口还没来得及关闭，接收线程在收到这个字节后检查while(!isInterrupted())不满足，就迅速退出run()了。

解决办法

给read()方法加上超时设置。需要修改linux底层串口终端配置，在SerialPort.c里添加以下代码：

// 设置read超时

LOGD("before set, vtime is %d", cfg.c_cc[VTIME]);

LOGD("before set, vmin is %d", cfg.c_cc[VMIN]);

cfg.c_cc[VTIME] = 10;

cfg.c_cc[VMIN] = 0;

LOGD("after set, vtime is %d", cfg.c_cc[VTIME]);

LOGD("after set, vmin is %d", cfg.c_cc[VMIN]);

关于VTIME和VMIN的说明参考这篇博文 [Linux串口中的超时设置]

设置前，通过log打印得知原来的VTIME为0，VMIN为1，即至少读到1个字节才会返回否则一直阻塞。

现在我们来检验一下增加超时后的效果，通过log打印信息还可以顺便分析未设置超时时出错的具体过程：

完整LoopBackActivity代码如下：

LoopBackActivity.java

public class LoopBackActivity extends SerialPortActivity {

private static final String TAG = "LoopBackActivity";

volatile byte mValueToSend;

volatile boolean mByteReceivedBack;

final Object mByteReceivedBackSemaphore = new Object();

volatile Integer mInComing = new Integer(0);

volatile Integer mOutGoing = new Integer(0);

volatile Integer mLost = new Integer(0);

volatile Integer mCorrupted = new Integer(0);

private SendingThread mSendingThread;

TextView mValueSentText;

TextView mInComingText;

TextView mOutGoingText;

TextView mLostText;

TextView mCorruptedText;

class SendingThread extends Thread {

@Override

public void run() {

while (!isInterrupted()) {

synchronized (mByteReceivedBackSemaphore) {

try {

Thread.sleep(100);

} catch (InterruptedException e) {

Log.d(TAG, "run: SendingThread is interrupted at " + System.currentTimeMillis());

}

mByteReceivedBack = false; // clear flag before sending

if (mOutputStream != null) {

try {

mOutputStream.write(mValueToSend);

} catch (IOException e) {

e.printStackTrace();

return;

}

} else return;

mOutGoing++;

Log.d(TAG, Thread.currentThread().getName() + " has sent " + mValueToSend

+ " at " + System.currentTimeMillis());

try {

mByteReceivedBackSemaphore.wait(100);

} catch (InterruptedException e) {}

Log.d(TAG, Thread.currentThread().getName() + " resumes at " + System.currentTimeMillis());

if (mByteReceivedBack == true) { // send success

mInComing++;

} else {

mLost++;

}

// show results on UI

runOnUiThread(new Runnable() {

@Override

public void run() {

mValueSentText.setText(String.valueOf(mValueToSend));

mInComingText.setText(String.format(Locale.getDefault(),"%d",mInComing));

mOutGoingText.setText(String.format(Locale.getDefault(),"%d",mOutGoing));

mLostText.setText(String.format(Locale.getDefault(),"%d",mLost));

mCorruptedText.setText(String.format(Locale.getDefault(),"%d",mCorrupted));

}

});

}

}

}

}

@Override

protected void onDataReceived(byte[] buffer, int size) {

synchronized (mByteReceivedBackSemaphore) {

for (int i = 0; i < size; i++) {

if (buffer[i] == mValueToSend && mByteReceivedBack == false) {

mValueToSend++;

mByteReceivedBack = true;

mByteReceivedBackSemaphore.notify();

Log.d(TAG, Thread.currentThread().getName() + " has notified at " + System.currentTimeMillis());

} else {

mCorrupted++;

}

}

}

}

@Override

protected void onCreate(Bundle savedInstanceState) {

mValueToSend = 0;

super.onCreate(savedInstanceState);

setContentView(R.layout.activity_loop_back);

mInComingText = (TextView)findViewById(R.id.TextViewIncomingValue);

mOutGoingText = (TextView)findViewById(R.id.TextViewOutgoingValue);

mLostText = (TextView)findViewById(R.id.TextViewLostValue);

mCorruptedText = (TextView)findViewById(R.id.TextViewCorruptedValue);

mValueSentText = (TextView)findViewById(R.id.TextViewCurrValueSent);

mSendingThread = new SendingThread();

mSendingThread.start();

}

@Override

protected void onDestroy() {

if (mSendingThread != null) {

mSendingThread.interrupt();

}

super.onDestroy();

}

}

SerialPortActivity.java

public abstract class SerialPortActivity extends AppCompatActivity {

private static final String TAG = "SerialPortActivity";

protected Application mApplication;

protected SerialPort mSerialPort;

protected OutputStream mOutputStream;

private InputStream mInputStream;

private ReadThread mReadThread;

private class ReadThread extends Thread {

@Override

public void run() {

super.run();

byte[] buffer = new byte[64];

int size;

while(!isInterrupted()) {

try {

if (mInputStream == null) return;

size = mInputStream.read(buffer);

if (size > 0) {

onDataReceived(buffer, size);

}

} catch (IOException e) {

e.printStackTrace();

return;

}

}

Log.d(TAG, "mReadThread quits while at" + System.currentTimeMillis());

}

}

@Override

protected void onCreate(Bundle savedInstanceState) {

super.onCreate(savedInstanceState);

mApplication = (Application)getApplication();

try {

mSerialPort = mApplication.getSerialPort();

mOutputStream = mSerialPort.getOutputStream();

mInputStream = mSerialPort.getInputStream();

/* Create a receiving thread */

mReadThread = new ReadThread();

mReadThread.start();

} catch (SecurityException e) {

DisplayError(R.string.error_security);

} catch (InvalidParameterException e) {

DisplayError(R.string.error_configuration);

} catch (IOException e) {

DisplayError(R.string.error_unknown);

}

}

private void DisplayError (int resourceID) {

AlertDialog.Builder b = new AlertDialog.Builder (this);

b.setTitle("Error");

b.setMessage(resourceID);

b.setPositiveButton("OK", new DialogInterface.OnClickListener() {

@Override

public void onClick(DialogInterface dialog, int which) {

SerialPortActivity.this.finish();

}

});

b.show();

}

protected abstract void onDataReceived(byte[] buffer, int size);

@Override

protected void onDestroy() {

if (mReadThread != null) {

mReadThread.interrupt();

Log.d(TAG, "onDestroy: mReadThread.interrupt() is called at " + System.currentTimeMillis());

}

mApplication.closeSerialPort();

Log.d(TAG, "onDestroy: SerialPort is closed at " + System.currentTimeMillis());

mSerialPort = null;

super.onDestroy();

}

}

不设置read()超时，即VTIME=0, VMIN=1时

mReadThread能正常退出的情况：

01-08 05:41:05.730 23490-23826/com.example.serialporttest D/LoopBackActivity: Thread-329 has sent 22 at 596465738

01-08 05:41:05.730 23490-23825/com.example.serialporttest D/LoopBackActivity: Thread-328 has notified at 596465739

01-08 05:41:05.740 23490-23826/com.example.serialporttest D/LoopBackActivity: Thread-329 resumes at 596465744

01-08 05:41:05.800 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 596465811

01-08 05:41:05.800 23490-23826/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 596465812

01-08 05:41:05.800 23490-23826/com.example.serialporttest D/LoopBackActivity: Thread-329 has sent 23 at 596465812

01-08 05:41:05.800 23490-23825/com.example.serialporttest D/LoopBackActivity: Thread-328 has notified at 596465813

01-08 05:41:05.800 23490-23825/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at596465813

01-08 05:41:05.800 23490-23826/com.example.serialporttest D/LoopBackActivity: Thread-329 resumes at 596465814

01-08 05:41:05.800 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 596465814

01-08 05:41:05.900 23490-23826/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 05:41:05.910 23490-23826/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

活动销毁时， 主线程中mReadThread.interrupt()先被调用，然后sleep中的SendingThread被interrupted后有幸发出最后一个字节"23"，mReadThread迅速捕捉到这个字节，发现自己中断标志置位，于是结束运行，最后串口才被关闭，SendingThread试图再次发送字节发生write异常然后结束运行。所以不会产生任何历史遗留问题。

再看mReadThread没能及时结束的情况

-- 异常退出1

01-08 05:43:48.960 23490-26112/com.example.serialporttest D/LoopBackActivity: Thread-331 has sent 53 at 596628972

01-08 05:43:48.960 23490-26111/com.example.serialporttest D/LoopBackActivity: Thread-330 has notified at 596628972

01-08 05:43:48.960 23490-26112/com.example.serialporttest D/LoopBackActivity: Thread-331 resumes at 596628974

01-08 05:43:49.010 23490-26112/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 596629017

01-08 05:43:49.010 23490-26112/com.example.serialporttest D/LoopBackActivity: Thread-331 has sent 54 at 596629018

01-08 05:43:49.010 23490-26111/com.example.serialporttest D/LoopBackActivity: Thread-330 has notified at 596629019

01-08 05:43:49.010 23490-26112/com.example.serialporttest D/LoopBackActivity: Thread-331 resumes at 596629019

01-08 05:43:49.010 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 596629021

01-08 05:43:49.010 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 596629022

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 05:43:49.110 23490-26112/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

01-08 05:48:22.620 23490-30131/com.example.serialporttest D/LoopBackActivity: Thread-333 has sent 0 at 596902634

01-08 05:48:22.620 23490-26111/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at596902634

01-08 05:48:22.720 23490-30131/com.example.serialporttest D/LoopBackActivity: Thread-333 resumes at 596902734

01-08 05:48:22.820 23490-30131/com.example.serialporttest D/LoopBackActivity: Thread-333 has sent 0 at 596902835

01-08 05:48:22.820 23490-30130/com.example.serialporttest D/LoopBackActivity: Thread-332 has notified at 596902835

01-08 05:48:22.830 23490-30131/com.example.serialporttest D/LoopBackActivity: Thread-333 resumes at 596902836

活动销毁时，sleep中的SendingThread(Thread-331)首先被interrupted后发出最后一个字节，mReadThread(Thread-330)迅速捕捉到这个字节，可惜此后它的中断标志才被置位，也就是说在中断标志置位前，它已经卡在read()了，直到新的SendingThread(Thread-333)发出第一个字节后，mReadThread(Thread-330)才能结束运行，此后新的mReadThread(Thread-332)才能接收到重发的第一个字节以及后面的字节。

异常退出2

01-08 06:00:14.440 23490-8067/com.example.serialporttest D/LoopBackActivity: Thread-335 has sent 22 at 597614449

01-08 06:00:14.440 23490-8066/com.example.serialporttest D/LoopBackActivity: Thread-334 has notified at 597614450

01-08 06:00:14.440 23490-8067/com.example.serialporttest D/LoopBackActivity: Thread-335 resumes at 597614450

01-08 06:00:14.480 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 597614492

01-08 06:00:14.480 23490-8067/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 597614493

01-08 06:00:14.480 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 597614493

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 06:00:14.480 23490-8067/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 06:00:14.490 23490-8067/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 06:00:14.490 23490-8067/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

01-08 06:02:52.290 23490-10364/com.example.serialporttest D/LoopBackActivity: Thread-337 has sent 0 at 597772299

01-08 06:02:52.290 23490-8066/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at597772300

01-08 06:02:52.390 23490-10364/com.example.serialporttest D/LoopBackActivity: Thread-337 resumes at 597772400

01-08 06:02:52.490 23490-10364/com.example.serialporttest D/LoopBackActivity: Thread-337 has sent 0 at 597772501

01-08 06:02:52.490 23490-10359/com.example.serialporttest D/LoopBackActivity: Thread-336 has notified at 597772501

01-08 06:02:52.490 23490-10364/com.example.serialporttest D/LoopBackActivity: Thread-337 resumes at 597772501

活动销毁时， 主线程中mReadThread.interrupt()先被调用，然后sleep中的SendingThread被interrupted，还没来得及发出下一个字节，串口就先关闭了，mReadThread等不来这个字节，只能卡在read()了，等待新的SendingThread来拯救它。

异常退出3

01-08 06:15:23.450 23490-21140/com.example.serialporttest D/LoopBackActivity: Thread-368 has sent 55 at 598523466

01-08 06:15:23.460 23490-21139/com.example.serialporttest D/LoopBackActivity: Thread-367 has notified at 598523466

01-08 06:15:23.460 23490-21140/com.example.serialporttest D/LoopBackActivity: Thread-368 resumes at 598523466

01-08 06:15:23.530 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 598523542

01-08 06:15:23.530 23490-23490/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 598523542

01-08 06:15:23.530 23490-21140/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 598523543

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 06:15:23.530 23490-21140/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 06:15:23.540 23490-21140/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 06:15:23.540 23490-21140/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

01-08 06:16:43.200 23490-22357/com.example.serialporttest D/LoopBackActivity: Thread-370 has sent 0 at 598603213

01-08 06:16:43.200 23490-21139/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at598603215

01-08 06:16:43.310 23490-22357/com.example.serialporttest D/LoopBackActivity: Thread-370 resumes at 598603316

01-08 06:16:43.410 23490-22357/com.example.serialporttest D/LoopBackActivity: Thread-370 has sent 0 at 598603416

01-08 06:16:43.410 23490-22356/com.example.serialporttest D/LoopBackActivity: Thread-369 has notified at 598603417

01-08 06:16:43.410 23490-22357/com.example.serialporttest D/LoopBackActivity: Thread-370 resumes at 598603418

活动销毁时， 主线程中mReadThread.interrupt()先被调用，紧接着串口就被关闭，然后SendingThread才缓缓醒来，当然无法发出字节了，mReadThread等不来这个字节，只能卡在read()了，等待新的SendingThread来拯救它。

可见，异常退出的情况有很多种，都是不能同时满足“中断标志先置位然后收到一个字节退出read()阻塞状态”这两个条件，这是由于多线程并发运行的随机性造成的，不打印出来还真不知道原来多线程并发运行时这么“随意”哈。

那么设置了超时后带来的效果，VTIME=10, VMIN=0, 即超时10*100ms后read()返回

先看mReadThread正常结束时，和不加超时设置时一样，超时还没发挥出它的威力：

01-08 05:33:42.240 29330-17495/com.example.serialporttest D/LoopBackActivity: Thread-333 has sent 49 at 596022254

01-08 05:33:42.240 29330-17494/com.example.serialporttest D/LoopBackActivity: Thread-332 has notified at 596022255

01-08 05:33:42.250 29330-17495/com.example.serialporttest D/LoopBackActivity: Thread-333 resumes at 596022262

01-08 05:33:42.330 29330-29330/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 596022344

01-08 05:33:42.330 29330-17495/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 596022345

01-08 05:33:42.330 29330-17495/com.example.serialporttest D/LoopBackActivity: Thread-333 has sent 50 at 596022346

01-08 05:33:42.340 29330-17494/com.example.serialporttest D/LoopBackActivity: Thread-332 has notified at 596022346

01-08 05:33:42.340 29330-17494/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at596022347

01-08 05:33:42.340 29330-17495/com.example.serialporttest D/LoopBackActivity: Thread-333 resumes at 596022348

01-08 05:33:42.340 29330-29330/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 596022350

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 05:33:42.440 29330-17495/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

再看mReadThread没能及时结束的情况

01-08 05:14:23.570 29330-780/com.example.serialporttest D/LoopBackActivity: Thread-329 has sent 39 at 594863585

01-08 05:14:23.580 29330-779/com.example.serialporttest D/LoopBackActivity: Thread-328 has notified at 594863586

01-08 05:14:23.580 29330-780/com.example.serialporttest D/LoopBackActivity: Thread-329 resumes at 594863586

01-08 05:14:23.620 29330-29330/com.example.serialporttest D/SerialPortActivity: onDestroy: mReadThread.interrupt() is called at 594863627

01-08 05:14:23.620 29330-29330/com.example.serialporttest D/SerialPortActivity: onDestroy: SerialPort is closed at 594863627

01-08 05:14:23.620 29330-780/com.example.serialporttest D/LoopBackActivity: run: SendingThread is interrupted at 594863627

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:464)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:187)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at java.io.FileOutputStream.write(FileOutputStream.java:192)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at com.example.serialporttest.LoopBackActivity$SendingThread.run(LoopBackActivity.java:45)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at libcore.io.Posix.writeBytes(Native Method)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at libcore.io.Posix.write(Posix.java:202)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at libcore.io.BlockGuardOs.write(BlockGuardOs.java:197)

01-08 05:14:23.620 29330-780/com.example.serialporttest W/System.err: at libcore.io.IoBridge.write(IoBridge.java:459)

01-08 05:14:24.580 29330-779/com.example.serialporttest D/SerialPortActivity: mReadThread quits while at594864586

活动销毁时， 主线程中mReadThread.interrupt()先被调用，紧接着串口就被关闭，然后SendingThread才缓缓醒来，当然无法发出字节了，mReadThread等不来这个字节，卡在read()，然而这回没有一直傻等下去，在等了1000ms左右后从read()超时返回，结束运行。(实测超时后，mInputStream.read(buffer)返回-1，说明串口设备的InputStream在超时后会认为达到流末尾)

增加超时后，间隔2秒以上(因为定时没那么准确)看到"quits while"后再重启活动，就绝对不会出现第一个字节“lost”了，但是间隔短于2秒的操作还是有可能"lost"第一个字节，不能接受的话，就把超时时间再设置的短一些吧。