为什么使用线程的脚本偶尔会打印多余行？

Question

如果把 print s 替换成 print >>sys.stderr, s，那么这个问题就消失了。

import random, sys, time
import threading

lock = threading.Lock()

def echo(s):
    time.sleep(1e-3*random.random()) # instead of threading.Timer()
    with lock:
        print s

for c in 'abc':
    threading.Thread(target=echo, args=(c,)).start()

示例

# Run until empty line is found:
$ while ! python example.py 2>&1|tee out|grep '^$';do echo -n .;done;cat out

输出

....................
b

c
a

输出中不应该有空行，但实际上却有。我知道 print 不是线程安全的，但我本以为加锁应该能解决这个问题。

问题是 为什么 会这样呢？

我的机器：

$ python -mplatform
Linux-2.6.38-11-generic-x86_64-with-Ubuntu-11.04-natty

在 py26、py27 和 pypy 上会多打印出空行。

而在 py24、py25、py31 和 py32 上表现正常（没有空行）。

变种

• sys.stdout.flush() 在 print 之后并不能解决这个问题：

  with lock:
      print(s)
      sys.stdout.flush()
  

• 更奇怪的是，普通的 sys.stdout.write() 在加锁的情况下不会产生空行：

  with lock:
      sys.stdout.write(s)
      sys.stdout.write('\n') #NOTE: no .flush()
  

• print 函数 按预期工作（没有空行）。

要重现这个问题，请 下载文件 并运行：

$ tox

Answer 1

因为打印操作是先把文本写到标准输出（也就是屏幕）上，然后再结束这个字符串。用伪代码来解释一下：

def print(*args, **kwargs):
    write_to_stdout(to_single_string(args))
    write_to_stdout(end)  # usually a newline "\n"

所以，在多线程的情况下，两个线程的第一个字符串会先执行，然后才是第二个字符串，这样就会同时打印出两个换行符。但是，为什么这两行不会在同一行呢？我也不太清楚。需要更深入地检查一下Python的打印实现。

Answer 2

看看这个StackOverflow的讨论：在Python 2.6中如何实现线程安全的打印？。显然，打印到标准输出（sout）并不是线程安全的。

如果你开启详细的线程调试，你会更清楚地看到这一点：

threading.Thread(target=echo, args=(c,), verbose=True).start()

我得到的输出是这样的：

MainThread: <Thread(Thread-1, initial)>.start(): starting thread
Thread-1: <Thread(Thread-1, started 6204)>.__bootstrap(): thread started
MainThread: <Thread(Thread-2, initial)>.start(): starting thread
Thread-2: <Thread(Thread-2, started 3752)>.__bootstrap(): thread started
MainThread: <Thread(Thread-3, initial)>.start(): starting thread
Thread-3: <Thread(Thread-3, started 4412)>.__bootstrap(): thread started
MainThread: <Thread(Thread-2, started 3752)>.join(): waiting until thread stops
a
b
Thread-1: <Thread(Thread-1, started 6204)>.__bootstrap(): normal return
Thread-2: <Thread(Thread-2, started 3752)>.__bootstrap(): normal return
MainThread: <Thread(Thread-2, stopped 3752)>.join(): thread stopped
MainThread: <Thread(Thread-3, started 4412)>.join(): waiting until thread stops
Thread-3: <Thread(Thread-3, started 4412)>.__bootstrap(): normal return
MainThread: <Thread(Thread-3, stopped 4412)>.join(): thread stopped
c

你可以看到线程3在打印字符'c'之前就显示完成了。这显然是不可能的，所以我推测打印到控制台并不是线程安全的。

不过，这并没有解释为什么打印到sys.stderr看起来是正常工作的。