[cmake-developers] For add_custom_command and add_custom_target does each COMMAND completely finish before the next COMMAND starts?

[Alan W. Irwin]

I asked the question in the subject line because I have been
obtaining some peculiar modification times to files.

The add_custom_command documentation states:

____________

COMMAND

Specify the command-line(s) to execute at build time. If more than one
COMMAND is specified they will be executed in order, but not
necessarily composed into a stateful shell or batch script.
____________

And the add_custom_target documentation says the same thing about its
COMMANDs.

The phrase "executed in order" is ambiguous because it could mean
either started execution in order with no waits until completion until the next
COMMAND is started or each COMMAND started and completely finished in order.  I am pretty sure what is
meant is the last meaning in which case it would be good to change
the above from

they will be executed in order

==>

they will be executed to completion in order

to be absolutely clear on this point.  And a similar change would need
to be made to the add_custom_target documentation.

I always assumed the "executed to completion" scenario until today when I
ran into the following "interesting" Linux file modification time
evidence to the contrary (for 3.6.2 if that makes any difference).
For this example, I created in a given add_custom_command (for the
ephcom software) the following sequential COMMANDs

COMMAND $<TARGET_FILE:ephcom_eph2asc>
${binary_ephemeris_full_path} EPHEMERIS_header_ascii
EPHEMERIS_data_ascii >
${CMAKE_BINARY_DIR}/${binary_results_dir}/${dir}/identity_eph2asc.out
2>&1

COMMAND $<TARGET_FILE:ephcom_asc2eph> EPHEMERIS_header_ascii
EPHEMERIS_data_ascii RECREATED_BINARY_EPHEMERIS >
${CMAKE_BINARY_DIR}/${binary_results_dir}/${dir}/identity_asc2eph.out
2>&1

and yet for the files generated with "make -j4" the modification times
are (from the Linux "ls -lth --full-time" command)

-rw-r--r-- 1 software software    0 2017-12-04 19:34:56.765613972 -0800 identity_eph2asc.out
-rw-r--r-- 1 software software 7.6K 2017-12-04 19:34:56.741614353 -0800 identity_asc2eph.out
-rw-r--r-- 1 software software 136M 2017-12-04 19:34:56.721614671 -0800 EPHEMERIS_data_ascii
-rw-r--r-- 1 software software  41M 2017-12-04 19:34:56.697615052 -0800 RECREATED_BINARY_EPHEMERIS
-rw-r--r-- 1 software software 7.4K 2017-12-04 19:34:47.097767483 -0800 EPHEMERIS_header_ascii
[...]
-rw-r--r-- 1 software software  41M 2017-12-04 19:25:57.974135445 -0800 JPLEPH

where JPLEPH is the same as ${binary_ephemeris_full_path} above, and
the first 5 files are output from the above two COMMANDs.

The puzzling thing is these modification times naively imply the
second command finished slightly before (!) the first command which
should lead to completely bogus results since the second command
depends on the EPHEMERIS_header_ascii and EPHEMERIS_data_ascii files
generated by the first command.  However, it turns out the results are
perfect as expected, i.e., RECREATED_BINARY_EPHEMERIS is exactly
identical to the starting ${binary_ephemeris_full_path} = JPLEPH in
the same directory verifying the eph2asc and asc2eph commands are
working perfectly for this particular set of ephemeris data.

Because of these perfect results I believe what is going on for this
interesting case is that these modification times are simply showing
Linux kernel optimization at work rather than the actual order of
command execution.  According to this hypothesis, the first command
completely finishes before the second command starts. But at that time
each of the EPHEMERIS_header_ascii, EPHEMERIS_data_ascii, and
identity_eph2asc.out files generated by the first command are handed
off to the Linux kernel for disposition.

And then the optimization fun begins. It makes sense that the kernel
would keep at least the first two core resident until the second
command finishes with them. And eventually all 5 file output results
are flushed to disk (with modification times written at flush time)
when both eph2asc and asc2eph are done with them. This hypothesis does
not explain why identity_eph2asc.out is not immediately flushed by the
Linux kernel when that first task is done, but my guess is the kernel
assigns the lowest priority to flushing small (i.e., zero-length in
this case) files which is why this file is the last to be flushed to
disk.  Also, I just checked and asc2eph opens EPHEMERIS_header_ascii,
reads it, and closes it right at the start of its execution and then
opens EPHEMERIS_data_ascii, and reads it through the rest of a much
longer execution time which explains why the Linux kernel took
advantage of that chance to flush EPHEMERIS_header_ascii so much
earlier than EPHEMERIS_data_ascii.

I would love to get some confirmation that I can absolutely rely on
COMMANDs being executed sequentially with each finishing (and handing
off their generated files to the kernel at that time for disposition)
before the next one is allowed to start.  And I hope I have convinced
the CMake developers that the above slight change in documentation
would be worthwhile to clarify this point.  I would also appreciate
corrections (if needed) to the above hypothesis to explain the
peculiar modification times I demonstrated above.

Alan
__________________________
Alan W. Irwin

Astronomical research affiliation with Department of Physics and Astronomy,
University of Victoria (astrowww.phys.uvic.ca).

Programming affiliations with the FreeEOS equation-of-state
implementation for stellar interiors (freeeos.sf.net); the Time
Ephemerides project (timeephem.sf.net); PLplot scientific plotting
software package (plplot.sf.net); the libLASi project
(unifont.org/lasi); the Loads of Linux Links project (loll.sf.net);
and the Linux Brochure Project (lbproject.sf.net).
__________________________

Linux-powered Science
__________________________