Subprocess WindowsError 5

场景是这样的,有一个app目录,里面有一个主程序main.py, 主程序会调用app目录外的updater.py对app目录进行升级:

下载新的包
重命名app为app_old
将新的包拷进来，成为新的app目录
删除app_old

说明: main.py和updater.py会使用pyinstaller打包成exe

但是在执行os.rename对目录进行重命名时发生错误了:

WindowsError: [Error 5]

问题模拟

app/main.py代码

主程序代码,启动时会打开一个日志文件. 然后调用updater.exe程序.



In [ ]:

    
# encoding: utf-8
import logging
import os
import subprocess
import sys

CUR_DIR = os.path.dirname(os.path.abspath(sys.argv[0]))

logging.basicConfig(filename=os.path.join(CUR_DIR, "app.log"),
                    filemode="w",level=logging.INFO,
                    format='%(asctime)s  [%(levelname)s]- %(message)s')
UPDATER = os.path.abspath(os.path.join(CUR_DIR, "..", "updater.exe"))


def main():
    subprocess.Popen([UPDATER])
    sys.exit()


if __name__ == "__main__":
    try:
        main()
    except Exception as e:
        pass

updater.py代码

启动后会对app目录重命名为app_old



In [ ]:

    
# -*- encoding: utf-8 -*-
import logging
import os
import sys
import zipfile

CUR_DIR = os.path.dirname(os.path.abspath(sys.argv[0]))

CACHE_DIR = os.path.join(CUR_DIR, "cache")
NEW_PACKAGE = os.path.join(CUR_DIR, "app.zip")

logging.basicConfig(filename=os.path.join(CUR_DIR, "updater.log"), filemode="w", level=logging.INFO,
                    format='%(asctime)s  [%(levelname)s]- %(message)s')


def update_files():
    logging.info(u"删除缓存目录:%s", CACHE_DIR)
    with zipfile.ZipFile(NEW_PACKAGE) as zip:
        zip.extractall(CACHE_DIR)
    
    app_cache_dir = os.path.join(CUR_DIR, "cache", "app")
    app_dir = os.path.join(CUR_DIR, "app")
    app_old_dir = os.path.join(CUR_DIR, "old_app")
    logging.info(u"替换目录%s 为 %s", app_dir, app_old_dir)
    os.rename(app_dir, app_old_dir)


if __name__ == "__main__":
    
    try:
        update_files()
    
    except Exception as e:
        logging.exception(e)

build.py 代码

将main.py打包成exe并复制到main.py相同的目录
将updater打包成exe并复制到updater.py相同目录

注意: 需要安装pyinstaller



In [ ]:

    
import sys
import os
import shutil
import subprocess

CUR_DIR = os.path.abspath(os.path.dirname(__file__))

APP_DIR = os.path.join(CUR_DIR, "app")

pyinstaller_exe = os.path.join(os.path.dirname(sys.executable) ,"Scripts", "pyinstaller.exe")

try:
    shutil.rmtree(os.path.join(CUR_DIR, "build"))
    shutil.rmtree(os.path.join(CUR_DIR, "dist"))
except:
    pass
subprocess.check_call("{pyinstaller} -w -F --onefile  --clean {script}".format(
    pyinstaller=pyinstaller_exe,
    script=os.path.join(CUR_DIR, "updater.py")
), shell=True, cwd=CUR_DIR)

shutil.copy(os.path.join(CUR_DIR, "dist", "updater.exe"),
                CUR_DIR)

try:
    shutil.rmtree(os.path.join(APP_DIR, "build"))
    shutil.rmtree(os.path.join(APP_DIR, "dist"))
except:
    pass
subprocess.check_call("{pyinstaller} -w -F --onefile  --clean {script}".format(
    pyinstaller=pyinstaller_exe,
    script=os.path.join(APP_DIR, "main.py")
), shell=True, cwd=APP_DIR)

shutil.copy(os.path.join(APP_DIR, "dist", "main.exe"),
                APP_DIR)

结果

2017-03-24 17:47:13,496  [ERROR]- [Error 5] 
Traceback (most recent call last):
  File "books\bug\subprocess_windowserror_5\updater.py", line 31, in <module>
  File "books\bug\subprocess_windowserror_5\updater.py", line 25, in update_files
WindowsError: [Error 5]

问题分析

没打包为exe前，代码运行正常。但是打包成exe后, 就出现Error 5了。看一下这句:

def main():
    subprocess.Popen([UPDATER])
    sys.exit()

主程序启动升级程序后就退出了,为什么还会出现Error 5呢，google上找了半天说什么权限、是否是管理员等问题，可是打包前都是正常的。问题到底出在哪里呢？难道是main.exe里日志文件被占用，但是程序是退出了的啊。我就下载了个Process Explorer尝试看一下日志文件是否被占用:

打开Process Explorer,如图:

点击那个望远镜图标打开查找界面:

输入app.log,竟然看到updater.exe进程占用着app.log文件，这时才恍然大悟: 原来windows程序子进程会进程父进程的句柄,导致updater.exe还持有父进程的app.log文件句柄.

问题解决

可以在启动升级进程钱关闭主进程的日志文件.

def main():
    subprocess.Popen([UPDATER])
    sys.exit()

改为

def main():
    logger = logging.getLogger()
    handlers = logger.handlers[:]
    for handler in handlers:
        handler.close()
        logger.removeHandler(handler)
    subprocess.Popen([UPDATER])
    sys.exit()