avoid calling show_config_info and show_config_variable when ARDUINO_…

[TE-HiroakiYamazoe]

…QUIET is defined

When slow machine or environments such as WSL is used, calling output script itself causes heavy overhead.
This pull request reduces the overhead when ARDUINO_QUIET is set.

[sej7278]

i get your point, not sure if overloading the recipes for show_config_info() and show_config_variable() is the way to go though

[TE-HiroakiYamazoe]

OK, simple check below helps us to understand this modification actually reduces the time.

$ cat /proc/version
Linux version 4.4.0-43-Microsoft ([email protected]) (gcc version 5.4.0 (GCC) ) #1-Microsoft Wed Dec 31 14:42:53 PST 2014
$ cat /proc/meminfo | head -1
MemTotal:        8181796 kB
$ cat /proc/cpuinfo | grep "model name" | head -1
model name      : Intel(R) Core(TM) i5-6200U CPU @ 2.30GHz
$ export ARDUINO_QUIET=1
$ pwd
/home/hiroaki/repository/Arduino-Makefile/examples/Blink
$ git branch
* master
  undef_show_script_with_quiet
$ git rev-parse HEAD
b2d1ff23a2ff6d824aced575401e7b0deace672c
$ make # ignore first result because first make includes build time
$ time make
mkdir -p build-uno

real    0m17.049s
user    0m0.219s
sys     0m3.797s

$ git checkout undef_show_script_with_quiet
Switched to branch 'undef_show_script_with_quiet'
$ make # ignore first result because first make includes build time
$ time make
mkdir -p build-uno

real    0m12.987s
user    0m0.125s
sys     0m3.656s

$ git rev-parse HEAD
b39ce310a86159f836cd7e23821f75facbee8efe

I also found configuration function such as PARSE_BOARD affects the performance.
This overhead can be reduced by pre-defining parameters such as ISP_HIGH_FUSE, ISP_LOW_FUSE, ISP_EXT_FUSE, and so on.

[TE-HiroakiYamazoe]

Hello. How can I proceed this discussion?
Maybe many poor develop environment can reproduce this performance improvement.

[wingunder]

Will the following not solve your problem?

Arduino-Makefile/Arduino.mk

Line 91 in 22ca636

# If you'd rather not see the configuration output, define ARDUINO_QUIET.

Could you please try the following on 'master' and post your result?
time (ARDUINO_QUIET=1 make)

[TE-HiroakiYamazoe]

Yes, it doesn't solve the problem.
As I mentioned to this issue title, my result above has already include ARDUINO_QUIET=1.
Doesn't anyone have the same issue? I guess WSL + slow machine can easily reproduce this.

[wingunder]

As I mentioned to this issue title, my result above has already include ARDUINO_QUIET=1.

Ah, my mistake. Sorry for that. My browser's font is set to large and it only displayed:
avoid calling show_config_info and show_config_variable when ARDUINO_… #579

In this case it must be a Win10 or a config problem. I'm using native Linux on hardware that's even slower than yours. I don't have this problem.

$ cat /proc/version
Linux version 4.18.0-1-amd64 ([email protected]) (gcc version 7.3.0 (Debian 7.3.0-29)) #1 SMP Debian 4.18.6-1 (2018-09-06)
$ cat /proc/cpuinfo | grep "model name" | head -1
model name      : Intel(R) Core(TM) i5-2467M CPU @ 1.60GHz
$ git rev-parse HEAD
b2d1ff23a2ff6d824aced575401e7b0deace672c
$ pwd
....../Arduino-Makefile/examples/Blink
$ time (make -j1 clean all 2>&1 |wc -l)
91

real    0m1.559s
user    0m1.363s
sys     0m0.463s

Maybe try benchmarking your build. I would suggest something like make -j1 2>&1 |tai64n |tai64nlocal |tee make.log to see what gets done when, and for how long. The tai64n and tai64nlocal utilities are part of the daemontools software.

Just a shot in the dark: Is your PATH set correctly (efficiently)? It could be that your OS is scanning several directories with lots and lots of files, before it finds the right executable. On top of that, you are running in a virtual machine, so directory/file scanning could be very time consuming.

[TE-HiroakiYamazoe]

As you mentioned, WSL certainly has large overhead. Because of it, this problem affect large impact with current WSL system.

But I don't think this is windows-specific issue.
Here is my another experiment with raspberry-pi. It is another slow environment which is independent from Windows.

$ cat /proc/version
Linux version 4.9.35-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #1014 SMP Fri Jun 30 14:47:43 BST 2017
$ cat /proc/meminfo | head -1
MemTotal:         945516 kB
$ cat /proc/cpuinfo | grep "model name" | head -1
model name      : ARMv7 Processor rev 5 (v7l)
$ lsb_release -a
No LSB modules are available.
Distributor ID: Raspbian
Description:    Raspbian GNU/Linux 8.0 (jessie)
Release:        8.0
Codename:       jessie
$ git rev-parse HEAD
b2d1ff23a2ff6d824aced575401e7b0deace672c
$ time (export ARDUINO_QUIET=1; make) # ignore first result because first make includes build time
$ time (export ARDUINO_QUIET=1; make)
mkdir -p build-uno
( export ARDUINO_QUIET=1; make; )  0.22s user 0.12s system 18% cpu 1.812 total
$ git checkout undef_show_script_with_quiet
Switched to branch 'undef_show_script_with_quiet'
raspberrypi:pi% git rev-parse HEAD
b39ce310a86159f836cd7e23821f75facbee8efe
$ time (export ARDUINO_QUIET=1; make) # ignore first result because first make includes build time
$ time (export ARDUINO_QUIET=1; make)
mkdir -p build-uno
( export ARDUINO_QUIET=1; make; )  0.15s user 0.09s system 18% cpu 1.325 total

As you can see, my pull request improves the performance 0.5 sec.
This improvement is smaller than the benchmark of WSL system. But it actually has effect.

[wingunder]

For sure something like PARSE_BOARD will take time, as we're checking for the existence, reading and parsing the board file. I guess that on a raspberry-pi, the disk access is also not the fastest, which could explain the 0.5 seconds. The question now is how it scales. i.e. Does the time saved increase, if the total build gets say 10 times larger.

@ALL: Is there someone that can point us to a 'large' public build, using Arduino-Makefile?

Now that you're on Debian (Raspbian), could you please install daemontools (apt install daemontools) and benchmark your 2 different builds and compare them, so that we can see what exactly takes so long (0.5 sec)?
make -j1 -p build-uno 2>&1 |tai64n |tai64nlocal > make.log