Opened at 2020-07-19T13:13:29Z
Last modified at 2020-07-19T14:40:02Z
#3347 assigned defect
Tor integration tests fail on Windows
| Reported by: | sajith | Owned by: | sajith |
|---|---|---|---|
| Priority: | normal | Milestone: | undecided |
| Component: | dev-infrastructure | Version: | n/a |
| Keywords: | Cc: | ||
| Launchpad Bug: |
Description (last modified by sajith)
Related to #3320: running integration tests on Windows fails, at least on GitHub Actions. For an example failure, see:
Change History (4)
comment:1 Changed at 2020-07-19T13:14:56Z by sajith
comment:2 Changed at 2020-07-19T13:17:46Z by sajith
Looks like the failure is in cloning chutney from https://git.torproject.org/chutney.git, but it is unclear why.
comment:3 Changed at 2020-07-19T14:39:44Z by sajith
- Owner set to sajith
- Status changed from new to assigned
comment:4 Changed at 2020-07-19T14:40:02Z by sajith
- Description modified (diff)
Note: See
TracTickets for help on using
tickets.
GitHub may purge the logs eventually, so here's the failure for future reference:
2020-06-23T00:15:45.2583036Z integration/test_aaa_aardvark.py::test_create_flogger PASSED [ 5%] 2020-06-23T00:15:57.6151796Z integration/test_aaa_aardvark.py::test_create_introducer PASSED [ 11%] 2020-06-23T00:16:23.5543904Z integration/test_aaa_aardvark.py::test_create_storage PASSED [ 16%] 2020-06-23T00:16:40.1798875Z integration/test_servers_of_happiness.py::test_upload_immutable PASSED [ 22%] 2020-06-23T00:17:49.9033565Z integration/test_streaming_logs.py::test_streaming_logs PASSED [ 27%] 2020-06-23T00:17:50.0034080Z integration/test_tor.py::test_onion_service_storage ERROR [ 33%] 2020-06-23T00:17:50.4545168Z integration/test_web.py::test_index PASSED [ 38%] 2020-06-23T00:17:50.5339962Z integration/test_web.py::test_index_json PASSED [ 44%] 2020-06-23T00:17:50.7801376Z integration/test_web.py::test_upload_download PASSED [ 50%] 2020-06-23T00:17:50.8310376Z integration/test_web.py::test_put PASSED [ 55%] 2020-06-23T00:17:51.0641041Z integration/test_web.py::test_helper_status PASSED [ 61%] 2020-06-23T00:17:52.2467157Z integration/test_web.py::test_deep_stats PASSED [ 66%] 2020-06-23T00:17:53.0700293Z integration/test_web.py::test_status PASSED [ 72%] 2020-06-23T00:17:58.8040475Z integration/test_web.py::test_directory_deep_check PASSED [ 77%] 2020-06-23T00:17:58.8255745Z integration/test_web.py::test_storage_info PASSED [ 83%] 2020-06-23T00:17:58.8256523Z integration/test_web.py::test_storage_info_json PASSED [ 88%] 2020-06-23T00:17:58.8256982Z integration/test_web.py::test_introducer_info PASSED [ 94%] 2020-06-23T00:18:01.0832885Z integration/test_web.py::test_mkdir_with_children PASSED [100%] 2020-06-23T00:18:01.0906746Z 2020-06-23T00:18:01.0907325Z =================================== ERRORS ==================================== 2020-06-23T00:18:01.0907627Z ________________ ERROR at setup of test_onion_service_storage _________________ 2020-06-23T00:18:01.0907836Z 2020-06-23T00:18:01.0908090Z reactor = <twisted.internet.selectreactor.SelectReactor object at 0x00000000033DE108> 2020-06-23T00:18:01.0908397Z temp_dir = 'c:\\users\\runner~1\\appdata\\local\\temp\\tahoeheselp' 2020-06-23T00:18:01.0908724Z 2020-06-23T00:18:01.0908971Z @pytest.fixture(scope='session') 2020-06-23T00:18:01.0909238Z def chutney(reactor, temp_dir): 2020-06-23T00:18:01.0909489Z chutney_dir = join(temp_dir, 'chutney') 2020-06-23T00:18:01.0909734Z mkdir(chutney_dir) 2020-06-23T00:18:01.0909971Z 2020-06-23T00:18:01.0910206Z # TODO: 2020-06-23T00:18:01.0910437Z 2020-06-23T00:18:01.0910648Z # check for 'tor' binary explicitly and emit a "skip" if we can't 2020-06-23T00:18:01.0910905Z # find it 2020-06-23T00:18:01.0911136Z 2020-06-23T00:18:01.0911386Z # XXX yuck! should add a setup.py to chutney so we can at least 2020-06-23T00:18:01.0911648Z # "pip install <path to tarball>" and/or depend on chutney in "pip 2020-06-23T00:18:01.0912005Z # install -e .[dev]" (i.e. in the 'dev' extra) 2020-06-23T00:18:01.0912220Z # 2020-06-23T00:18:01.0912485Z # https://trac.torproject.org/projects/tor/ticket/20343 2020-06-23T00:18:01.0912736Z proto = _DumpOutputProtocol(None) 2020-06-23T00:18:01.0912948Z reactor.spawnProcess( 2020-06-23T00:18:01.0913158Z proto, 2020-06-23T00:18:01.0913452Z 'git', 2020-06-23T00:18:01.0913599Z ( 2020-06-23T00:18:01.0913786Z 'git', 'clone', '--depth=1', 2020-06-23T00:18:01.0913998Z 'https://git.torproject.org/chutney.git', 2020-06-23T00:18:01.0914204Z chutney_dir, 2020-06-23T00:18:01.0914413Z ), 2020-06-23T00:18:01.0914598Z > env=environ, 2020-06-23T00:18:01.0914789Z ) 2020-06-23T00:18:01.0914935Z 2020-06-23T00:18:01.0915080Z integration\conftest.py:384: 2020-06-23T00:18:01.0915275Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 2020-06-23T00:18:01.0915482Z .tox\integration\lib\site-packages\twisted\internet\posixbase.py:353: in spawnProcess 2020-06-23T00:18:01.0917093Z return Process(self, processProtocol, executable, args, env, path) 2020-06-23T00:18:01.1659932Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 2020-06-23T00:18:01.1673656Z 2020-06-23T00:18:01.1679573Z self = <Process pid=None> 2020-06-23T00:18:01.1682355Z reactor = <twisted.internet.selectreactor.SelectReactor object at 0x00000000033DE108> 2020-06-23T00:18:01.1685766Z protocol = <integration.util._DumpOutputProtocol instance at 0x00000000085AEB88> 2020-06-23T00:18:01.1793792Z command = 'git' 2020-06-23T00:18:01.1804563Z args = ['git', 'clone', '--depth=1', 'https://git.torproject.org/chutney.git', 'c:\users\runner~1\appdata\local\temp\tahoeheselp\chutney'] 2020-06-23T00:18:01.1807055Z environment = {'COMSPEC': 'C:\\windows\\system32\\cmd.exe', 'COVERAGE_PROCESS_START': '.coveragerc', 'HOMEDRIVE': 'C:', 'HOMEPATH': '\\Users\\runneradmin', ...} 2020-06-23T00:18:01.1815417Z path = None 2020-06-23T00:18:01.1999481Z 2020-06-23T00:18:01.2001061Z def __init__(self, reactor, protocol, command, args, environment, path): 2020-06-23T00:18:01.2019596Z """ 2020-06-23T00:18:01.2022230Z Create a new child process. 2020-06-23T00:18:01.2052576Z """ 2020-06-23T00:18:01.2063732Z _pollingfile._PollingTimer.__init__(self, reactor) 2020-06-23T00:18:01.2072475Z BaseProcess.__init__(self, protocol) 2020-06-23T00:18:01.2084363Z 2020-06-23T00:18:01.2085961Z # security attributes for pipes 2020-06-23T00:18:01.2086536Z sAttrs = win32security.SECURITY_ATTRIBUTES() 2020-06-23T00:18:01.2086828Z sAttrs.bInheritHandle = 1 2020-06-23T00:18:01.2217916Z 2020-06-23T00:18:01.2218420Z # create the pipes which will connect to the secondary process 2020-06-23T00:18:01.2218727Z self.hStdoutR, hStdoutW = win32pipe.CreatePipe(sAttrs, 0) 2020-06-23T00:18:01.2219042Z self.hStderrR, hStderrW = win32pipe.CreatePipe(sAttrs, 0) 2020-06-23T00:18:01.2219342Z hStdinR, self.hStdinW = win32pipe.CreatePipe(sAttrs, 0) 2020-06-23T00:18:01.2219763Z 2020-06-23T00:18:01.2220032Z win32pipe.SetNamedPipeHandleState(self.hStdinW, 2020-06-23T00:18:01.2220324Z win32pipe.PIPE_NOWAIT, 2020-06-23T00:18:01.2220616Z None, 2020-06-23T00:18:01.2220954Z None) 2020-06-23T00:18:01.2221207Z 2020-06-23T00:18:01.2221469Z # set the info structure for the new process. 2020-06-23T00:18:01.2221744Z StartupInfo = win32process.STARTUPINFO() 2020-06-23T00:18:01.2221974Z StartupInfo.hStdOutput = hStdoutW 2020-06-23T00:18:01.2222237Z StartupInfo.hStdError = hStderrW 2020-06-23T00:18:01.2222500Z StartupInfo.hStdInput = hStdinR 2020-06-23T00:18:01.2222770Z StartupInfo.dwFlags = win32process.STARTF_USESTDHANDLES 2020-06-23T00:18:01.2223026Z 2020-06-23T00:18:01.2223300Z # Create new handles whose inheritance property is false 2020-06-23T00:18:01.2223578Z currentPid = win32api.GetCurrentProcess() 2020-06-23T00:18:01.2223831Z 2020-06-23T00:18:01.2224129Z tmp = win32api.DuplicateHandle(currentPid, self.hStdoutR, currentPid, 0, 0, 2020-06-23T00:18:01.2224441Z win32con.DUPLICATE_SAME_ACCESS) 2020-06-23T00:18:01.2224717Z win32file.CloseHandle(self.hStdoutR) 2020-06-23T00:18:01.2224983Z self.hStdoutR = tmp 2020-06-23T00:18:01.2225482Z 2020-06-23T00:18:01.2225890Z tmp = win32api.DuplicateHandle(currentPid, self.hStderrR, currentPid, 0, 0, 2020-06-23T00:18:01.2226279Z win32con.DUPLICATE_SAME_ACCESS) 2020-06-23T00:18:01.2226656Z win32file.CloseHandle(self.hStderrR) 2020-06-23T00:18:01.2226914Z self.hStderrR = tmp 2020-06-23T00:18:01.2227086Z 2020-06-23T00:18:01.2227308Z tmp = win32api.DuplicateHandle(currentPid, self.hStdinW, currentPid, 0, 0, 2020-06-23T00:18:01.2227651Z win32con.DUPLICATE_SAME_ACCESS) 2020-06-23T00:18:01.2228065Z win32file.CloseHandle(self.hStdinW) 2020-06-23T00:18:01.2228304Z self.hStdinW = tmp 2020-06-23T00:18:01.2228532Z 2020-06-23T00:18:01.2228780Z # Add the specified environment to the current environment - this is 2020-06-23T00:18:01.2229044Z # necessary because certain operations are only supported on Windows 2020-06-23T00:18:01.2229299Z # if certain environment variables are present. 2020-06-23T00:18:01.2229535Z 2020-06-23T00:18:01.2229769Z env = os.environ.copy() 2020-06-23T00:18:01.2230012Z env.update(environment or {}) 2020-06-23T00:18:01.2230212Z newenv = {} 2020-06-23T00:18:01.2230457Z for key, value in items(env): 2020-06-23T00:18:01.2230686Z 2020-06-23T00:18:01.2230922Z key = _fsdecode(key) 2020-06-23T00:18:01.2231164Z value = _fsdecode(value) 2020-06-23T00:18:01.2231396Z 2020-06-23T00:18:01.2231632Z newenv[key] = value 2020-06-23T00:18:01.2231865Z 2020-06-23T00:18:01.2232094Z env = newenv 2020-06-23T00:18:01.2232322Z 2020-06-23T00:18:01.2232577Z # Make sure all the arguments are Unicode. 2020-06-23T00:18:01.2232826Z args = [_fsdecode(x) for x in args] 2020-06-23T00:18:01.2233058Z 2020-06-23T00:18:01.2233292Z cmdline = quoteArguments(args) 2020-06-23T00:18:01.2233525Z 2020-06-23T00:18:01.2233733Z # The command, too, needs to be Unicode, if it is a value. 2020-06-23T00:18:01.2233989Z command = _fsdecode(command) if command else command 2020-06-23T00:18:01.2234244Z path = _fsdecode(path) if path else path 2020-06-23T00:18:01.2234479Z 2020-06-23T00:18:01.2234720Z # TODO: error detection here. See #2787 and #4184. 2020-06-23T00:18:01.2234962Z def doCreate(): 2020-06-23T00:18:01.2235249Z flags = win32con.CREATE_NO_WINDOW 2020-06-23T00:18:01.2235512Z self.hProcess, self.hThread, self.pid, dwTid = win32process.CreateProcess( 2020-06-23T00:18:01.2235867Z command, cmdline, None, None, 1, flags, env, path, StartupInfo) 2020-06-23T00:18:01.2236116Z try: 2020-06-23T00:18:01.2236355Z doCreate() 2020-06-23T00:18:01.2236600Z except pywintypes.error as pwte: 2020-06-23T00:18:01.2236809Z if not _invalidWin32App(pwte): 2020-06-23T00:18:01.2237087Z # This behavior isn't _really_ documented, but let's make it 2020-06-23T00:18:01.2237352Z # consistent with the behavior that is documented. 2020-06-23T00:18:01.2237598Z > raise OSError(pwte) 2020-06-23T00:18:01.2238987Z E OSError: (2, 'CreateProcess', 'The system cannot find the file specified.') 2020-06-23T00:18:01.2239225Z 2020-06-23T00:18:01.2239481Z .tox\integration\lib\site-packages\twisted\internet\_dumbwin32proc.py:232: OSError 2020-06-23T00:18:01.2239757Z ==================== 17 passed, 1 error in 142.26 seconds ===================== 2020-06-23T00:18:01.2240128Z ERROR: InvocationError for command 'D:\a\tahoe-lafs\tahoe-lafs\.tox\integration\Scripts\py.test.EXE' --coverage -v integration (exited with code 1) 2020-06-23T00:18:01.2240372Z ___________________________________ summary ___________________________________ 2020-06-23T00:18:01.2240590Z ERROR: integration: commands failed 2020-06-23T00:18:06.4175335Z ##[error]Process completed with exit code 1.