Include cache fixes and refactorings #236

matthijskooijman · 2017-06-16T19:21:17Z

This PR fixes a few corner cases in the include caching and refactors some code in the process. In particular, this fixes the issue reported at #230. The problem in that report consisted of three parts:

arduino-builder would fail to remove the -MMD option from commandline for the chipKIT32 boards, due to the way their platform.txt was structured. This caused the preprocessor command to fail, trying to write to /dev/null.d.
The preprocessor command would be run a second time to show an error, but with slightly different options, which prevented the error from occuring. This caused arduino-builder to ignore the failure and continue, masking the above problem.
Because the include cache would now be in a half-finished state, a small bug in the include caching was triggered that caused an out-of-bounds array read and a panic.

This PR fixes all three problems (in reverse order), with a fair amount of refactoring in between (some of which is strictly needed, some of which is "while I'm here").

ArduinoBot · 2017-06-16T19:36:29Z

✅ Build completed.

⬇️ Build URL: http://downloads.arduino.cc/PR/arduino-builder/arduino-builder-236.zip

ℹ️ To test this build:

Replace arduino-builder binary (you can find it where you installed the IDE) with the provided one

facchinm

Overall it looks really good, particularly generalisation through ExecCommand function.

Anyway, a lot of functions turned into using the global context; while the new signatures are slightly more readable, unit-testing could be much more convoluted but I don't have a strong opinion about it.

matthijskooijman · 2017-06-22T13:59:15Z

Anyway, a lot of functions turned into using the global context; while the new signatures are slightly more readable, unit-testing could be much more convoluted but I don't have a strong opinion about it.

The policy I'm using here is that these helper functions can access things like ctx.DebugLevel and ctx.Verbose, which are essentially just global flags, but should still use explicit arguments for things like the list of files to compiler, or the buildProperties to use (even when these are also available through the context). In the long run, I think the latter should actually be removed from the context and be explicitely passed from function to function instead, to reduce the amount of implicit dataflow.

matthijskooijman · 2017-09-26T09:47:39Z

@facchinm pointed out some benchmarks that show this PR significantly slows down compilation. This needs some investigation before merging this PR.

ArduinoBot · 2017-11-29T09:59:50Z

❌ Build failed.

matthijskooijman · 2017-11-30T14:10:33Z

I can't really reproduce the slow benchmarks of #242. I tried PR232, this PR, and this PR after rebasing, which all give similar times (there's a bit of variation, but I was using my computer while running these texts, so that probably explains the small differences).

                                                PR232    PR236    PR236 rebased
TestTryBuild001   ok    arduino.cc/builder/test 2.398s   2.103s   2.281s
TestTryBuild002   ok    arduino.cc/builder/test 2.081s   2.022s   1.977s
TestTryBuild003   ok    arduino.cc/builder/test 0.124s   0.133s   0.129s
TestTryBuild004   ok    arduino.cc/builder/test 1.997s   2.018s   1.982s
TestTryBuild005   ok    arduino.cc/builder/test 2.275s   2.162s   2.236s
TestTryBuild006   ok    arduino.cc/builder/test 2.105s   1.979s   2.094s
TestTryBuild007   ok    arduino.cc/builder/test 3.393s   3.375s   3.391s
TestTryBuild009   ok    arduino.cc/builder/test 2.039s   2.038s   2.030s
TestTryBuild010   ok    arduino.cc/builder/test 2.083s   2.038s   1.954s
TestTryBuild011   ok    arduino.cc/builder/test 2.008s   2.051s   2.043s
TestTryBuild012   ok    arduino.cc/builder/test 2.012s   2.043s   2.043s
TestTryBuild013   ok    arduino.cc/builder/test 2.066s   2.005s   2.077s
TestTryBuild014   ok    arduino.cc/builder/test 2.008s   2.006s   2.049s
TestTryBuild015   ok    arduino.cc/builder/test 2.351s   2.238s   2.287s
TestTryBuild017   ok    arduino.cc/builder/test 0.206s   0.320s   0.173s
TestTryBuild018   ok    arduino.cc/builder/test 2.242s   3.001s   2.258s
TestTryBuild019   ok    arduino.cc/builder/test 2.020s   2.626s   1.976s
TestTryBuild020   ok    arduino.cc/builder/test 0.221s   0.316s   0.221s
TestTryBuild021   ok    arduino.cc/builder/test 2.105s   2.370s   2.003s
TestTryBuild022   ok    arduino.cc/builder/test 9.257s   10.876s  9.241s
TestTryBuild023   ok    arduino.cc/builder/test 2.023s   2.429s   2.303s
TestTryBuild024   ok    arduino.cc/builder/test 1.999s   2.000s   2.627s
TestTryBuild026   ok    arduino.cc/builder/test 2.578s   2.655s   3.495s
TestTryBuild027   ok    arduino.cc/builder/test 2.307s   2.305s   2.600s
TestTryBuild028   ok    arduino.cc/builder/test 2.051s   2.160s   2.429s
TestTryBuild029   ok    arduino.cc/builder/test 2.069s   1.980s   2.721s
TestTryBuild030   ok    arduino.cc/builder/test 1.982s   2.191s   2.493s
TestTryBuild031   ok    arduino.cc/builder/test 3.461s   3.398s   4.421s
TestTryBuild032   ok    arduino.cc/builder/test 2.130s   2.211s   2.129s
TestTryBuild033   ok    arduino.cc/builder/test 1.960s   2.044s   1.999s
TestTryBuild034   ok    arduino.cc/builder/test 1.990s   2.039s   2.055s
TestTryBuild035   ok    arduino.cc/builder/test 1.973s   1.963s   2.007s
TestTryBuild036   ok    arduino.cc/builder/test 8.696s   8.847s   9.243s
TestTryBuild037   ok    arduino.cc/builder/test 2.003s   1.989s   2.010s
TestTryBuild038   ok    arduino.cc/builder/test 2.008s   1.978s   2.002s
TestTryBuild039   ok    arduino.cc/builder/test 5.239s   5.788s   5.368s
TestTryBuild040   ok    arduino.cc/builder/test 2.017s   2.588s   1.969s
TestTryBuild041   ok    arduino.cc/builder/test 1.990s   2.696s   1.977s
TestTryBuild042   ok    arduino.cc/builder/test 1.973s   2.478s   1.960s

For testing, I used for i in TestTryBuild{001..042}; do echo -ne "$i "; go test arduino.cc/builder/test -run $i;done

@facchinm, So it seems this PR can be merged? I'll ask in the other PR to see if those benchmarks can be reproduced, just in case, but I don't think this should block this PR any longer. I've also just rebased this PR on top of master, and re-ran the test suite, which still works.

ArduinoBot · 2017-11-30T14:11:42Z

✅ Build completed.

⬇️ Build URL: http://downloads.arduino.cc/PR/arduino-builder/arduino-builder-236.zip

ℹ️ To test this build:

Replace arduino-builder binary (you can find it where you installed the IDE) with the provided one

matthijskooijman · 2017-11-30T14:57:48Z

I also added three more cleanup commits from #217 (since that PR isn't quite ready, but those cleanup commits are fine to merge already).

ArduinoBot · 2017-11-30T15:01:47Z

✅ Build completed.

⬇️ Build URL: http://downloads.arduino.cc/PR/arduino-builder/arduino-builder-236.zip

ℹ️ To test this build:

Replace arduino-builder binary (you can find it where you installed the IDE) with the provided one

matthijskooijman · 2017-12-06T14:28:41Z

@facchinm, it indeed seems like the slowness of this PR was a one-off glitch, see #242 (comment)

The comments state that if ExpectFile() is called, but there are no remaining items in the cache, it will invalidate the cache. However, the code would only invalidate the cache if at least one item was still present, but it didn't match the expected file. In practice, this wouldn't usually cause issues, since adding a new file would usually cause an invalid cache earlier on, and even if a new file was added at the end of the compilation, it would not be in the .d file, so it would be marked as "changed". However, in rare circumstances, such as when the include cache would not be properly generated due to other problems (see arduino#230), this would cause a crash, when ExpectFile did not invalidate the cache and the file in question was unchanged, causing an out-of-bounds read from the cache. This commit fixes this by making ExpectFile behave like documented and invalidate the cache when there are no remaining entries. Signed-off-by: Matthijs Kooijman <[email protected]>

Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, the relative filename passed to GCCPreprocRunner() was made absolute by prepareGCCPreprocRecipeProperties() and then returned, so it could be used later on. There was an exception to this when /dev/null was passed. Now, the only place that passed something other than /dev/null simply does this processing up front instead. This prepares the way for removing Context::FileToRead in the next commit. Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, this filename was set by GCCPreprocRunner into the context, because the full filename was not known until then. Since the previous commit, this filename is known by the ContainerAddPrototypes, which can just pass it to ReadFileAndStoreInContext explicitly. This allows Context::FileToRead to be removed. Signed-off-by: Matthijs Kooijman <[email protected]>

This pass was unused. Signed-off-by: Matthijs Kooijman <[email protected]>

Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, the verbose, logger and sometimes warningFlags were extracted from the Context by the top-level runner and passed down separately. Since this causes a lot of variable-passing of what is essentially global state, it is clearer to just pass a types.Context down and let the helpers get the data they need from that state. This prepared for a next commit where ExecRecipe will be refactored and needs access to the Context. Since the next commit will heavily change ExecRecipe anyway, this commit does not actually change ExecRecipe to accept the Context. This commit should not change any behaviour. Signed-off-by: Matthijs Kooijman <[email protected]>

For some reason the sizer commandline was never shown. For consistency, it is now shown in verbose mode, just like the other commands. Signed-off-by: Matthijs Kooijman <[email protected]>

This also happens with the normal compilation commands, so why not with these? Normally these commands should not output to stdout, so this doesn't make any difference, but it makes things more consistent. Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, this function would ignore any errors returned by `Run()` since the command is expected to fail in most cases. However, in addition to ignoring a non-zero exit code from the command, it would also ignore errors in running the command itself. With this commit, `ExecRecipeCollectStdErr()` simply returns all errors, but its caller checks the type of the error. If it is `ExitError`, this indicates a non-zero exit status, which is ignored. Otherwise, the error is reported as normal. Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, the return value was converted to string. Letting callers convert to string makes it easier to write the sterr contents to os.Stderr again in a future commit. Signed-off-by: Matthijs Kooijman <[email protected]>

For include detection, the preprocessor is run on all source files, collecting #included filenames from the stderr output, each of which are then resolved to a library to include. A caching mechanism is used to only run the preprocessor when needed. This commit improves the error handling during include detection in a number of ways: - When the preprocessor runs succesfully, processing stops for the current file. Previously, it would always look at stderr to find a missing include filename and only stop if none was found. - When the preprocessor fails, but no filename can be found, show the error preprocessor error. Previously, it would assume that the process was done and stop processing the file without any error. - When no library can be found for a missing include, show the stored error output instead of running the preprocessor again. Previously, the preprocessor would be run a second time, to (re)generate the error message. When the include filename comes from the cache and the preprocessor was not run yet, it is still run to show its errors to the user. This should be very rare, as normally changes that cause a cached filename to become unresolvable to a library also cause the file to be marked as changed, bypassing the cache. When this does happen, the preprocessor is now run using `GCCPreprocRunnerForDiscoveringIncludes()` instead of `GCCPreprocRunner()`, which ensures the preprocessor command is always exactly the same. Before this change, there could be specific circumstances where the first preprocessor run would generate an error, but where the second run would not show the error and include detection would continue as if nothing happened. One such circumstance is described in arduino#230. Signed-off-by: Matthijs Kooijman <[email protected]>

This unifies these similar methods into a single method. The interface is additionally changed to: - Accepts a `Context` argument. - Allow for defaults and named arguments, using an `ExecOptions` struct that is passed as an argument. - Allow configuring command output handling in a flexible way. Instead of passing bools for some specific configurations, you can now pass either `Ignore`, `Show` or `Capture` for both stdout and stderr independently. By default, stdout is is shown when verbose is true, or ignored when verbose is false. Stderr is shown by default. - Actually redirect stdout to `/dev/null` when it is not needed (by leaving `command.Stdout` at nil). Previously, `ExecRecipe` would either show or capture stdout, and the captured output was usually just thrown away. To allow for even more reuse, the biggest part of `ExecRecipe` is extracted into a new `utils.ExecCommand()` function which executes an arbitrary `exec.Cmd` object, with configurable output redirection. Signed-off-by: Matthijs Kooijman <[email protected]>

Signed-off-by: Matthijs Kooijman <[email protected]>

Previously, the command was printed by PrepareCommandForRecipe. Letting ExecCommand print seems more accurate, since it is only printed when it is actually run (though this already happened in practice). Additionally, the command can now be modified between PrepareCommandForRecipe and ExecCommand while preserving correct output. Since ExecCommand deals with a slice of arguments instead of a single command string, this requires merging them together into a proper commandline. Some care is taken to quote arguments containing spaces, quotes or backslashes, though this is mostly intended for display purposes. Arguments are only quoted when needed, regardless of whether they were quoted in the original pattern. Signed-off-by: Matthijs Kooijman <[email protected]>

Usually, the `preproc.macros` recipe includes the C/C++ flags, and through that the `-MMD` flag to generate dependency files. However, since include detection passed an output file of `/dev/null` (or the equivalent on other operating systems), this causes gcc to try and generate a `/dev/null.d` file and fail. To prevent this, the `-MMD` flag was filtered out, but this filtering was applied to the `compiler.cpp.flags` variable, where it *usually* comes from. However, this is not necessarily true for all platforms. For example, the PIC32 platform used to have this flag in the `compiler.c.flags` variable and have `compiler.cpp.flags` include that. This prevented the flag from being filtered away and caused a failure. Due to previous changes, it is now possible for this filtering to happen after all variables have been replaced and the command to run was generated, but before actually running it. An extra advantage is that the filtering is more robust than the previous substring-based filtering. This fixes arduino#230. Signed-off-by: Matthijs Kooijman <[email protected]>

This slightly simplifies the code. Signed-off-by: Matthijs Kooijman <[email protected]>

This does not use the passed variable yet, but prepares for a future commit. Signed-off-by: Matthijs Kooijman <[email protected]>

If -debug-level=20 is passed, whenever the cached file is not usable for whatever reason, a message is displayed. This should help debug caching problems. The messages are hardcoded in the source and not put into `constants`, since they are only debug messages. Signed-off-by: Matthijs Kooijman <[email protected]>

This slightly cleans up a function call. Signed-off-by: Matthijs Kooijman <[email protected]>

matthijskooijman · 2018-05-28T14:26:22Z

@facchinm @cmaglie, I just rebased this PR again, so it applies cleanly now. Could we perhaps merge this? Any issues were resolved, and since it touches quite some code, it is likely to run into new conflicts if we leave this unmerged.

ArduinoBot · 2018-05-28T14:31:38Z

✅ Build completed.

⬇️ Build URL: http://downloads.arduino.cc/PR/arduino-builder/arduino-builder-236.zip

ℹ️ To test this build:

Replace arduino-builder binary (you can find it where you installed the IDE) with the provided one

cmaglie · 2018-06-01T10:06:14Z

Everything has been manually merged.

matthijskooijman · 2018-06-01T10:19:00Z

Thanks!

matthijskooijman requested review from cmaglie and facchinm June 16, 2017 19:21

matthijskooijman force-pushed the include-cache-fix branch from f5dc854 to 13176dc Compare June 16, 2017 19:32

arduino deleted a comment from ArduinoBot Jun 19, 2017

matthijskooijman mentioned this pull request Jun 22, 2017

Builder crashes on second run arduino/Arduino#6407

Closed

facchinm reviewed Jun 22, 2017

View reviewed changes

matthijskooijman mentioned this pull request Sep 4, 2017

Locale issue with includes finder #243

Open

matthijskooijman mentioned this pull request Sep 26, 2017

Use relative paths if commandline is too long #249

Closed

matthijskooijman force-pushed the include-cache-fix branch from 13176dc to 7f2d410 Compare November 30, 2017 14:10

matthijskooijman mentioned this pull request Nov 30, 2017

Parallel compiling: arduino-builder will leverage your multi core pc #242

Closed

matthijskooijman mentioned this pull request Nov 30, 2017

WIP: Include caching improved #217

Open

matthijskooijman added 10 commits May 28, 2018 15:59

Convert IncludesFinderWithRegExp to a normal function

f69a8cc

Signed-off-by: Matthijs Kooijman <[email protected]>

Convert GCCPreprocRunner(ForDiscoveringIncludes) to a normal function

be08809

Signed-off-by: Matthijs Kooijman <[email protected]>

Remove GCCPreprocSourceSaver

73bae11

This pass was unused. Signed-off-by: Matthijs Kooijman <[email protected]>

execSizeRecipe: Fix typo in method name

b861a84

Signed-off-by: Matthijs Kooijman <[email protected]>

Show the sizer commandline in verbose mode

0f1baa5

For some reason the sizer commandline was never shown. For consistency, it is now shown in verbose mode, just like the other commands. Signed-off-by: Matthijs Kooijman <[email protected]>

matthijskooijman added 11 commits May 28, 2018 16:15

Let ExecRecipeCollectStdErr return []byte for stderr

5eb37bc

Previously, the return value was converted to string. Letting callers convert to string makes it easier to write the sterr contents to os.Stderr again in a future commit. Signed-off-by: Matthijs Kooijman <[email protected]>

Merge some duplicate code into prepareGCCPreprocRecipeProperties

31e42b7

Signed-off-by: Matthijs Kooijman <[email protected]>

Use utils.ExecCommand for running ctags

788cecd

This slightly simplifies the code. Signed-off-by: Matthijs Kooijman <[email protected]>

Pass Context to ObjFileIsUpToDate

cc978ec

This does not use the passed variable yet, but prepares for a future commit. Signed-off-by: Matthijs Kooijman <[email protected]>

ContainerFindIncludes: Add some temporary variables

d2d49e6

This slightly cleans up a function call. Signed-off-by: Matthijs Kooijman <[email protected]>

matthijskooijman force-pushed the include-cache-fix branch from 20236c6 to d2d49e6 Compare May 28, 2018 14:28

cmaglie closed this Jun 1, 2018

cmaglie added this to the 1.3.26 milestone Jun 1, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Include cache fixes and refactorings #236

Include cache fixes and refactorings #236

matthijskooijman commented Jun 16, 2017

ArduinoBot commented Jun 16, 2017

facchinm left a comment

matthijskooijman commented Jun 22, 2017

matthijskooijman commented Sep 26, 2017

ArduinoBot commented Nov 29, 2017

matthijskooijman commented Nov 30, 2017

ArduinoBot commented Nov 30, 2017

matthijskooijman commented Nov 30, 2017

ArduinoBot commented Nov 30, 2017

matthijskooijman commented Dec 6, 2017

matthijskooijman commented May 28, 2018

ArduinoBot commented May 28, 2018

cmaglie commented Jun 1, 2018

matthijskooijman commented Jun 1, 2018

Include cache fixes and refactorings #236

Include cache fixes and refactorings #236

Conversation

matthijskooijman commented Jun 16, 2017

ArduinoBot commented Jun 16, 2017

facchinm left a comment

Choose a reason for hiding this comment

matthijskooijman commented Jun 22, 2017

matthijskooijman commented Sep 26, 2017

ArduinoBot commented Nov 29, 2017

matthijskooijman commented Nov 30, 2017

ArduinoBot commented Nov 30, 2017

matthijskooijman commented Nov 30, 2017

ArduinoBot commented Nov 30, 2017

matthijskooijman commented Dec 6, 2017

matthijskooijman commented May 28, 2018

ArduinoBot commented May 28, 2018

cmaglie commented Jun 1, 2018

matthijskooijman commented Jun 1, 2018