在学习android_serialport_api的LoopBackActivity例程时遇到的接收线程没有正常退出的问题和解决过程 2017年9月4日

问题背景

在实现git上的开源串口驱动api(android_serialport_api)的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标志应该就能及时退出呀。如下:

 1  private class ReadThread extends Thread {
 2
 3         @Override
 4
 5         public void run() {
 6
 7             super.run();
 8
 9             byte[] buffer = new byte[64];
10
11             int size;
12
13             while(!isInterrupted()) {
14
15                 try {
16
17                     if (mInputStream == null) return;
18
19                     size = mInputStream.read(buffer);
20
21                     if (size > 0) {
22
23                         onDataReceived(buffer, size);
24
25                     }
26
27                 } catch (IOException e) {
28
29                     e.printStackTrace();
30
31                     return;
32
33                 }
34
35             }
36
37             Log.d(TAG, "mReadThread quits while at" + System.currentTimeMillis());
38
39         }
40
41     }

在反复看那些文字后,我突然对“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里添加以下代码:

 1 // 设置read超时
 2
 3 LOGD("before set, vtime is %d", cfg.c_cc[VTIME]);
 4
 5 LOGD("before set, vmin is %d", cfg.c_cc[VMIN]);
 6
 7 cfg.c_cc[VTIME] = 10;
 8
 9 cfg.c_cc[VMIN] = 0;
10
11 LOGD("after set, vtime is %d", cfg.c_cc[VTIME]);
12
13 LOGD("after set, vmin is %d", cfg.c_cc[VMIN]);

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

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

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

完整LoopBackActivity代码如下:

LoopBackActivity.java

  1 public class LoopBackActivity extends SerialPortActivity {
  2
  3
  4
  5     private static final String TAG = "LoopBackActivity";
  6
  7
  8
  9     volatile byte mValueToSend;
 10
 11     volatile boolean mByteReceivedBack;
 12
 13     final Object mByteReceivedBackSemaphore = new Object();
 14
 15
 16
 17     volatile Integer mInComing = new Integer(0);
 18
 19     volatile Integer mOutGoing = new Integer(0);
 20
 21     volatile Integer mLost = new Integer(0);
 22
 23     volatile Integer mCorrupted = new Integer(0);
 24
 25
 26
 27     private SendingThread mSendingThread;
 28
 29
 30
 31     TextView mValueSentText;
 32
 33     TextView mInComingText;
 34
 35     TextView mOutGoingText;
 36
 37     TextView mLostText;
 38
 39     TextView mCorruptedText;
 40
 41
 42
 43     class SendingThread extends Thread {
 44
 45         @Override
 46
 47         public void run() {
 48
 49             while (!isInterrupted()) {
 50
 51                 synchronized (mByteReceivedBackSemaphore) {
 52
 53                     try {
 54
 55                         Thread.sleep(100);
 56
 57                     } catch (InterruptedException e) {
 58
 59                         Log.d(TAG, "run: SendingThread is interrupted at " + System.currentTimeMillis());
 60
 61                     }
 62
 63                     mByteReceivedBack = false; // clear flag before sending
 64
 65                     if (mOutputStream != null) {
 66
 67                         try {
 68
 69                             mOutputStream.write(mValueToSend);
 70
 71                         } catch (IOException e) {
 72
 73                             e.printStackTrace();
 74
 75                             return;
 76
 77                         }
 78
 79                     } else return;
 80
 81                     mOutGoing++;
 82
 83                     Log.d(TAG, Thread.currentThread().getName() + " has sent " + mValueToSend
 84
 85                     + " at " + System.currentTimeMillis());
 86
 87                     try {
 88
 89                         mByteReceivedBackSemaphore.wait(100);
 90
 91                     } catch (InterruptedException e) {}
 92
 93                     Log.d(TAG, Thread.currentThread().getName() + " resumes at " + System.currentTimeMillis());
 94
 95                     if (mByteReceivedBack == true) { // send success
 96
 97                         mInComing++;
 98
 99                     } else {
100
101                         mLost++;
102
103                     }
104
105
106
107                     // show results on UI
108
109                     runOnUiThread(new Runnable() {
110
111                         @Override
112
113                         public void run() {
114
115                             mValueSentText.setText(String.valueOf(mValueToSend));
116
117                             mInComingText.setText(String.format(Locale.getDefault(),"%d",mInComing));
118
119                             mOutGoingText.setText(String.format(Locale.getDefault(),"%d",mOutGoing));
120
121                             mLostText.setText(String.format(Locale.getDefault(),"%d",mLost));
122
123                             mCorruptedText.setText(String.format(Locale.getDefault(),"%d",mCorrupted));
124
125                         }
126
127                     });
128
129                 }
130
131             }
132
133         }
134
135     }
136
137
138
139     @Override
140
141     protected void onDataReceived(byte[] buffer, int size) {
142
143         synchronized (mByteReceivedBackSemaphore) {
144
145             for (int i = 0; i < size; i++) {
146
147                 if (buffer[i] == mValueToSend && mByteReceivedBack == false) {
148
149                     mValueToSend++;
150
151                     mByteReceivedBack = true;
152
153                     mByteReceivedBackSemaphore.notify();
154
155                     Log.d(TAG, Thread.currentThread().getName() + " has notified at " + System.currentTimeMillis());
156
157                 } else {
158
159                     mCorrupted++;
160
161                 }
162
163             }
164
165         }
166
167     }
168
169
170
171     @Override
172
173     protected void onCreate(Bundle savedInstanceState) {
174
175         mValueToSend = 0;
176
177         super.onCreate(savedInstanceState);
178
179         setContentView(R.layout.activity_loop_back);
180
181         mInComingText = (TextView)findViewById(R.id.TextViewIncomingValue);
182
183         mOutGoingText = (TextView)findViewById(R.id.TextViewOutgoingValue);
184
185         mLostText = (TextView)findViewById(R.id.TextViewLostValue);
186
187         mCorruptedText = (TextView)findViewById(R.id.TextViewCorruptedValue);
188
189         mValueSentText = (TextView)findViewById(R.id.TextViewCurrValueSent);
190
191         mSendingThread = new SendingThread();
192
193         mSendingThread.start();
194
195     }
196
197
198
199     @Override
200
201     protected void onDestroy() {
202
203         if (mSendingThread != null) {
204
205             mSendingThread.interrupt();
206
207         }
208
209         super.onDestroy();
210
211     }
212
213 }
214
215  

LoopBackActivity

SerialPortActivity.java

  1 public abstract class SerialPortActivity extends AppCompatActivity {
  2
  3
  4
  5     private static final String TAG = "SerialPortActivity";
  6
  7
  8
  9     protected Application mApplication;
 10
 11     protected SerialPort mSerialPort;
 12
 13     protected OutputStream mOutputStream;
 14
 15     private InputStream mInputStream;
 16
 17     private ReadThread mReadThread;
 18
 19
 20
 21     private class ReadThread extends Thread {
 22
 23         @Override
 24
 25         public void run() {
 26
 27             super.run();
 28
 29             byte[] buffer = new byte[64];
 30
 31             int size;
 32
 33             while(!isInterrupted()) {
 34
 35                 try {
 36
 37                     if (mInputStream == null) return;
 38
 39                     size = mInputStream.read(buffer);
 40
 41                     if (size > 0) {
 42
 43                         onDataReceived(buffer, size);
 44
 45                     }
 46
 47                 } catch (IOException e) {
 48
 49                     e.printStackTrace();
 50
 51                     return;
 52
 53                 }
 54
 55             }
 56
 57             Log.d(TAG, "mReadThread quits while at" + System.currentTimeMillis());
 58
 59         }
 60
 61     }
 62
 63
 64
 65     @Override
 66
 67     protected void onCreate(Bundle savedInstanceState) {
 68
 69         super.onCreate(savedInstanceState);
 70
 71         mApplication = (Application)getApplication();
 72
 73         try {
 74
 75             mSerialPort = mApplication.getSerialPort();
 76
 77             mOutputStream = mSerialPort.getOutputStream();
 78
 79             mInputStream = mSerialPort.getInputStream();
 80
 81
 82
 83             /* Create a receiving thread */
 84
 85             mReadThread = new ReadThread();
 86
 87             mReadThread.start();
 88
 89         } catch (SecurityException e) {
 90
 91             DisplayError(R.string.error_security);
 92
 93         } catch (InvalidParameterException e) {
 94
 95             DisplayError(R.string.error_configuration);
 96
 97         } catch (IOException e) {
 98
 99             DisplayError(R.string.error_unknown);
100
101         }
102
103
104
105     }
106
107
108
109     private void DisplayError (int resourceID) {
110
111         AlertDialog.Builder b = new AlertDialog.Builder (this);
112
113         b.setTitle("Error");
114
115         b.setMessage(resourceID);
116
117         b.setPositiveButton("OK", new DialogInterface.OnClickListener() {
118
119             @Override
120
121             public void onClick(DialogInterface dialog, int which) {
122
123                 SerialPortActivity.this.finish();
124
125             }
126
127         });
128
129         b.show();
130
131     }
132
133
134
135     protected abstract void onDataReceived(byte[] buffer, int size);
136
137
138
139     @Override
140
141     protected void onDestroy() {
142
143         if (mReadThread != null) {
144
145             mReadThread.interrupt();
146
147             Log.d(TAG, "onDestroy: mReadThread.interrupt() is called at " + System.currentTimeMillis());
148
149         }
150
151         mApplication.closeSerialPort();
152
153         Log.d(TAG, "onDestroy: SerialPort is closed at " + System.currentTimeMillis());
154
155         mSerialPort = null;
156
157         super.onDestroy();
158
159     }
160
161 }
162
163  

SerialPortActivity

不设置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"第一个字节,不能接受的话,就把超时时间再设置的短一些吧。

时间: 2024-09-30 09:22:44

在学习android_serialport_api的LoopBackActivity例程时遇到的接收线程没有正常退出的问题和解决过程 2017年9月4日的相关文章

2017年 1月 15日 指针 学习整理

有关指针的概念: 指针是一个特殊的变量,它里面存储的数值被解释为内存里的一个地址. FIrst of all:我们需要明确目标 关于指针的学习以及使用我们需要搞清楚有关指针的四个内容:指针的类型,指针所指向的类型,指针的值(或者说叫指针所指向的内存区),还有指针本身所占用的内存区(指针也是一个特殊的变量吗,它肯定也是占据内存的).接下来让我们分别进行学习. 我们先来申明几个指针的例子: 1 int *ptr; 2 char *ptr; 3 int **ptr; 4 int (*ptr)[3];

2017年3月30日上午学习日志

2017年3月30日上午复习了高等数学,学习高等数学教材书第二章第一节导数概念,并按照自己的思路记笔记,并背英语单词及其语法.

2017年8月9日学习内容存放 #socket通信介绍

2017年8月9日学习内容存放 1 #socket通信介绍 2 3 ''' 4 OSI七层 5 6 应用 7 表示 8 会话 9 传输 10 网络 ip 11 数据链路 mac 12 物理层 网线 13 14 15 16 http 17 smtp 18 dns 19 ftp 20 ssh 21 snmp 22 icmp ping 23 dhcp 24 25 26 27 发 send 28 收 receive 29 30 31 32 33 TCP/IP 三次握手,四次断开 34 35 UDP 36

154173503 傅欧瑞 现代软件工程工作室半月(2017年 月 日~2017年6月1日)学习情况总结

学习内容总结 主要学习了JAVA语言的一些应用,对Intellij IDEA的一些基本操作 学习中的问题和解决过程 问题1:做任务想当然去做 问题1解决方案:通过参考他人程序以及再度阅读要求对原程序进行更改 问题2:对数字的处理不到位 问题2解决方案:通过参考他人程序 学习成果 代码地址:https://github.com/Lixuskinkon/GitExtensionsDemo 感悟 这学期可以说是荒废了的一学期,积极性无法保持就开始对工作室比较上心,后来由于一些因素,学业荒废了一段时间,

关于开源金融计算学习的总结(截至2017年1月3日)

本文在Creative Commons许可证下发布 开源金融计算,源自开源数值计算.实际上需要学习以下内容就可以应对金融计算了. 1.Linux/Unix基本命令,2.Shell基本编程(这可能会花你一天时间),最好除了shell编程之外至少学一种脚本语言(建议Perl或Python).3.再根据你的需要选学下面某种数学分析软件:R,Scilab,Octave,C/C++(虽然不是"软件",但是做金融数学的人多半都用它写算法,不少投行.证券的研究部也在用它.有时候你遇到用上面的软件处理

微信小程序开发视频教程学习(第6天)2017年6月29日:上午前端下午PHP

学习内容 上午前端:CSS学习 下午PHP:  系统函数 笔记 1.CSS优先级顺序 行内样式 > 内部样式 > 导入样式 说明: 1.链入外部样式表和内部样式表的优先级取决于所处位置的先后 2.根据就近原则(最后定义的优先级最高) 2.链接伪类的顺序,按照这个顺序才是有效的 :Link  >  :Visited  > :Hover >:Active 3.PHP的字符串函数 ucfirst() //将句子的首字母转换为大写 ucwords() //将句子的每个单词替换为大写

2017年 1月15日 欧拉回路 学习整理

欧拉回路 欧拉通路: 通过图中每条边且只通过一次,并且经过每一顶点的通路(顶点并不要求都应经过一遍) 欧拉回路: 通过图中每条边且只通过一次,并且经过每一顶点的回路 有向图的基图:忽略有向图所有边的方向,得到的无向图称为该有向图的基图. 无向图 设G是连通无向图,则称经过G的每条边一次并且仅一次的路径为欧拉通路: 如果欧拉通路是回路(起点和终点是同一个顶点),则称此回路是欧拉回路 具有欧拉回路的无向图G成为欧拉图 有向图 (1)设D是有向图,D的基图连通,则称经过D的每条边一次并且仅有一次的有向

2017年2月12日 WER学习总结

今天中午,我们梦寐以求的WER场地和机器人器材终于到了,我与cby开始了器材的熟悉工作,经过一个下午的熟悉,我总结得到了场地搭建注意事项. 附件: 搭建注意事项 器材应先分类整理好,以免找的时候手忙脚乱 初次搭建时应按照指南按步骤有序搭建,可以根据指南先将装置拆分 应该在搭建过程中了解,熟记器材的名字 两个立方体块(红色立方体块)的拆分可以用70梁作撬棒(杠杆原理) 两倍三倍插销从孔立拔出的方法可以用80轴顶出来 插销与梁连接的时候应注意梁是否可以旋转(方口固定,圆口可转) 红色立方体块拆的时候

零基础学习云计算及大数据DBA集群架构师【Linux系统\网络服务及安全配置2015年1月8日周五】

考试考一天,得分94,最后一题防火墙当时还没搞明白 考题如下: 注意事项: 1.确保在重启主机后所有配置仍然生效. 2.selinux 必须为Enforing 模式,防火墙必须开始.默认策略必须清空. 3.设置主机名为stuXXX.com(“X”为你的foundation 机器ip 地址最后一位.例如:你的ip 地址为172.25.254.30,则你的主机名为stu30.com) 4.不允许ssh 登录到其他主机,已经发现按0 分计算考试得分. 5.考试满分为100 分制,70 分为及格,所有考