从Python调用BCP时抛出超时异常后立即完成

Question

我在运行一个Python脚本，这个脚本会调用一个子进程。结果它超时了，然后我立刻看到那个子进程（在这个例子中是一个BCP调用）完成了。实际上，我可以在数据库里看到它已经完成了。此外，我可以直接在命令行上运行BCP命令，它也能正常工作。

这是我的Python脚本在命令提示符下输出的内容：

C:\FaceIAPS\StudyDataFiles> py .\RUN_DATA.py
Synchronizing 80 subjects
Subject 11

Starting copy...
Traceback (most recent call last):
  File ".\RUN_DATA.py", line 261, in <module>
    bulk_import(upload_file, 'Facet_Data')
  File ".\RUN_DATA.py", line 171, in bulk_import
    subprocess.check_call("bcp BehaviorResearch.." + table_to_upload_to + " in " +     filename_to_be_uploaded + " -T -c -S
PBB-C202B-2\BEHAVIORRESEARCH -e bulk_copy_errors.log", shell=True, timeout=5)
  File "C:\Python34\lib\subprocess.py", line 554, in check_call
    retcode = call(*popenargs, **kwargs)
  File "C:\Python34\lib\subprocess.py", line 537, in call
    return p.wait(timeout=timeout)
  File "C:\Python34\lib\subprocess.py", line 1157, in wait
    raise TimeoutExpired(self.args, timeout)
subprocess.TimeoutExpired: Command 'bcp BehaviorResearch..Facet_Data in _temp_ -T -c -S     PBB-C202B-2\BEHAVIORRESEARCH -e
bulk_copy_errors.log' timed out after 5 seconds
1000 rows sent to SQL Server. Total sent: 1000
1000 rows sent to SQL Server. Total sent: 2000
PS C:\FaceIAPS\StudyDataFiles> 1000 rows sent to SQL Server. Total sent: 3000
1000 rows sent to SQL Server. Total sent: 4000
1000 rows sent to SQL Server. Total sent: 5000
1000 rows sent to SQL Server. Total sent: 6000
1000 rows sent to SQL Server. Total sent: 7000
1000 rows sent to SQL Server. Total sent: 8000
1000 rows sent to SQL Server. Total sent: 9000
1000 rows sent to SQL Server. Total sent: 10000
1000 rows sent to SQL Server. Total sent: 11000
1000 rows sent to SQL Server. Total sent: 12000
1000 rows sent to SQL Server. Total sent: 13000
1000 rows sent to SQL Server. Total sent: 14000
1000 rows sent to SQL Server. Total sent: 15000
1000 rows sent to SQL Server. Total sent: 16000

16102 rows copied.
Network packet size (bytes): 4096
Clock Time (ms.) Total     : 5164   Average : (3118.13 rows per sec.)

如你所见，命令提示符的输出被BCP调用的结果分开了。
这到底是怎么回事，我该怎么解决呢？

编辑：我怎么解决的

把子进程的调用改成：

arguments = ["bcp", "BehaviorResearch.." + table_to_upload_to, "in", filename_to_be_uploaded, "-T", "-c", "-S PBB-C202B-2\BEHAVIORRESEARCH", "-e bulk_copy_errors.log"]
subprocess.call(arguments, timeout=30)

顺便说一下，对于不太了解的人来说，“in”是它自己的一个参数。

Answer 1

关于 subprocess.check_call() 的文档提到：

timeout 参数会传递给 Popen.wait()。如果超时了，子进程会被杀掉，然后再等待它结束。超时异常会在子进程结束后再次抛出。

而 subprocess 的源代码也证实了这一点：

def call(*popenargs, timeout=None, **kwargs):
    with Popen(*popenargs, **kwargs) as p:
        try:
            return p.wait(timeout=timeout)
        except:
            p.kill() # kill on any exception including TimeoutExpired
            p.wait()
            raise

也就是说，你看到的就是预期的行为：如果超时发生，运行 bcp 进程的命令行窗口（%COMSPEC% 或 cmd.exe）会被迅速终止，这样可能会导致 bcp 进程本身也被终止。

你可能会看到在子进程已经退出后，控制台中缓冲的输出被刷新，或者（我不太确定）你看到的是活着的子进程 bcp 的输出，而它的父进程 cmd.exe 已经结束（新的提示符出现了）。

如果你去掉 shell=True，就可以避免创建不必要的中间 cmd.exe 进程，这样就可以直接对 bcp 进程调用 .kill()，而不是对命令行窗口进程。