python多线程读取logcat内容，导致其他线程阻塞

Question

问题描述

背景：
通过adb读取安卓设备上的数据内容，包括logcat日志以及其他系统文件内容。实现方式是在python中启动多线程，每个线程中通过popen执行系统命令，如adb logcat -s tag:*，或者adb shell cat /proc/stat。
读取文件在communicate中等待返回结果，logcat由于是不断滚动输出，因此从流中逐行读取，即stdout.readline()

问题描述：
在实际运行中发现，logcat的popen会阻塞其他读取文件的popen；但logcat的线程中sleep 1秒后，再启动其他线程，则没有阻塞现象

相关代码

复现源码：
使用python2.7执行，需要提前连接好安卓手机，打开调试模式

from subprocess import Popen, PIPE
import threading
from threading import Thread
import time

pid = 19622  # change to your pid in mobile

def run_logcat():
    """start logcat ,readline from logcat and print"""
    print "start logcat thread , %s" % threading.currentThread().getName()
    logcat = "adb logcat -v time "
    cat_open = Popen(logcat, stdout=PIPE, stderr=PIPE, universal_newlines=True)
    index = 0
    while index < 20:
        print threading.currentThread().getName()
        print cat_open.stdout.readline()
        time.sleep(1)
        index += 1
        print "index %s" % index
    cat_open.terminate()
    # cat_open.kill()

def run_sys():
    print "start sys thread , %s" % threading.currentThread().getName()
    index = 0
    while True:
        syst = "adb shell cat /proc/stat"
        sys_open = Popen(syst, stdout=PIPE, stderr=PIPE, universal_newlines=True)
        print threading.currentThread().getName() + str(index)
        print sys_open.communicate()
        print "sys open return code %d" % sys_open.returncode
        time.sleep(1)
        index += 1
        if index > 20:
            break

def run_proc():
    print "start proc thread, %s" % threading.currentThread().getName()
    index = 0
    while True:
        proc = "adb shell cat /proc/%s/stat" % pid
        proc_open = Popen(proc, stdout=PIPE, stderr=PIPE, universal_newlines=True)
        print threading.currentThread().getName() + str(index)
        print proc_open.communicate()
        print "proc open return code %s " % proc_open.returncode
        time.sleep(1)
        index += 1
        if index > 20:
            break

def run():
    logcat_t = Thread(target=run_logcat, name="locat_thread")
    proc_t = Thread(target=run_proc, name="proc_thread")
    sys_t = Thread(target=run_sys, name="sys_thread")

    logcat_t.start()
    # time.sleep(1) # if start logcat first and slepp 1s, proc thread ad sys thread will not blck

    # proc thread,and sys trhead is block
    proc_t.start()
    sys_t.start()

if __name__ == "__main__":
    run()

在网上找了一张adb 发送、传输指令的时序图，猜测可能是跟adb server有关。在多线程同时向adb server发送指令时，可能会导致后续指令阻塞。如果在python单线程顺序发送指令，或者多线程有sleep的情况下，则不会阻塞。
但是，阻塞在哪一步；阻塞情况怎样才会出现，却不是很清楚。

请问是哪个步骤导致阻塞？

Answer 1

我觉得多半和logcat无关，虽然我不了解logcat，但是验证它会不会有多进程阻塞只要两个命令行窗口同时运行两个logcat实例即可，不是吗？

@vibiu 提到的那篇文章说到了点子上，因为popen并发调用时，多个子进程继承了父进程打开的管道fd而未关闭所致。如果想更深的了解原因，建议看看APUE上thread and fork的章节，以及专门讲popen和pclose函数的部分。

我不太提倡thread + fork process 这种设计，线程共享资源和子进程继承的进程环境可能会带来复杂的冲突。POSIX pthread 库还有个专门的接口 pthread_atfork() 处理锁的问题，我还不知道python里有没有对应的机制。

楼主的场景，其实使用简单的os.popen更好，看源码os.popen是调用了subprocess.Popen，并且close_fds参数设置为True （python2.7中 subprocess.Popen这个参数默认是False）

Answer 2

堵塞多半发生在 IO 上, 我认为应该是因为文件加锁的缘故.

如果把你给出的程序中的run_logcat中的cat_open.terminate()去掉的话, 你会发现这个程序堵塞住了, 就像这样:

当它运行到index=20后就一直堵塞住不继续执行. 这是因为adb logcat就是阻塞的, 直接运行这个命令会发现它打印之前的日志后还在继续监听日志文件的变化并输出, 而这Popen作为这个命令的父进程, 需要继续为它提供一个输出文件(stdout), 导致打开的文件句柄一直无法得到关闭. 考虑到logcat_t, proc_t, sys_t使用的是同一个输入输出文件, 因此如果在logcat_t加上的文件锁不被释放, proc_t和sys_t永远不会拿到这个文件的读写锁, 程序就阻塞了. 但是如果调用cat_open.terminate(), logcat_t线程就直接结束, 文件锁就得到释放, 因此proc_t, sys_t得以继续执行.(我不知道我这样描述是不是会有点乱, 但思路应该是这样子的).

为什么加上time.sleep(1)之后就不会出现堵塞情况呢? 这个不清楚了, time.sleep(0.002)实测堵塞依旧, 但是time.sleep(0.003)之后堵塞就消除了.

这篇文章可能对你有些帮助:
python 并发subprocess.Popen的坑