scons: possible race condition in msvc tools cache

This is not a well investigated issue, just dropping something here to get it “written down”.

A couple of builds on Windows have failed with what looks like corruption in the msvc cache file. This isn’t confirmed to be consistently reproducible, but has been seen at least twice now, with an error that looks like this (this one is a real capture, the other one I saw wasn’t saved, I just retried and it worked - which, if it was a race, would make sense, because unlike the CI setup where the cache is rebuilt for each new image spun up, mine stays around):

[00:17:38] 605/1266 (47.79%) C:\Python36\python.exe test\MSVC\MSVC_SPECTRE_LIBS.py
[00:17:38] C:\projects\scons\scripts\scons.py returned 2
[00:17:38] STDOUT =========================================================================
[00:17:38]
[00:17:38] STDERR =========================================================================
[00:17:38] JSONDecodeError: Expecting ',' delimiter: line 382 column 125 (char 24284):
[00:17:38]   File "C:\Users\appveyor\AppData\Local\Temp\1\testcmd.4240.tmk0iejo\SConstruct", line 3:
[00:17:38]     env = Environment(MSVC_VERSION='11.0', MSVC_SPECTRE_LIBS=None, tools=['msvc'])
[00:17:38]   File "C:\projects\scons\SCons\Environment.py", line 1030:
[00:17:38]     apply_tools(self, tools, toolpath)
[00:17:38]   File "C:\projects\scons\SCons\Environment.py", line 116:
[00:17:38]     _ = env.Tool(tool)
[00:17:38]   File "C:\projects\scons\SCons\Environment.py", line 1911:
[00:17:38]     tool(self)
[00:17:38]   File "C:\projects\scons\SCons\Tool\__init__.py", line 265:
[00:17:38]     self.generate(env, *args, **kw)
[00:17:38]   File "C:\projects\scons\SCons\Tool\msvc.py", line 298:
[00:17:38]     msvc_setup_env_once(env, tool=tool_name)
[00:17:38]   File "C:\projects\scons\SCons\Tool\MSCommon\vc.py", line 1110:
[00:17:38]     msvc_setup_env(env)
[00:17:38]   File "C:\projects\scons\SCons\Tool\MSCommon\vc.py", line 1259:
[00:17:38]     d = msvc_find_valid_batch_script(env,version) 
[00:17:38]   File "C:\projects\scons\SCons\Tool\MSCommon\vc.py", line 1162:
[00:17:38]     d = script_env(env, vc_script, args=arg)
[00:17:38]   File "C:\projects\scons\SCons\Tool\MSCommon\vc.py", line 1009:
[00:17:38]     script_env_cache = common.read_script_env_cache()
[00:17:38]   File "C:\projects\scons\SCons\Tool\MSCommon\common.py", line 125:
[00:17:38]     envcache_list = json.load(f)
[00:17:38]   File "C:\Python36\lib\json\__init__.py", line 299:
[00:17:38]     parse_constant=parse_constant, object_pairs_hook=object_pairs_hook, **kw)
[00:17:38]   File "C:\Python36\lib\json\__init__.py", line 354:
[00:17:38]     return _default_decoder.decode(s)
[00:17:38]   File "C:\Python36\lib\json\decoder.py", line 339:
[00:17:38]     obj, end = self.raw_decode(s, idx=_w(s, 0).end())
[00:17:38]   File "C:\Python36\lib\json\decoder.py", line 355:
[00:17:38]     obj, end = self.scan_once(s, idx)

If it was a race, we could see one test creating the cache and another test come along, see the cache exists and proceed to read it, but catch it before it’s all written. But I think many tests would already have run which would have caused the cache to be created, so maybe it’s a different kind of race.

Perhaps the code in Tool/MSCommon/common.py should be catching JSONDecodeError and doing something better with it than dying?

About this issue

  • Original URL
  • State: open
  • Created 2 years ago
  • Comments: 21 (14 by maintainers)

Most upvoted comments

Cache file (22.7mb json, 477kb zip): scons_msvc_cache.zip

Log ouput:

Running scons (16:24:48.36) ...
...
Total: builds: 6644, cache: 6477
...
Scons finished (20:46:40.12)