An example of what the output looks like on PR #1254 :

Okay.. This is causing segfaults in CI.. That is a disappointment..

In addition to the segfault, we have other challenges right now trying to extract the ninja_logs from the build for each package in CI (conda build wants to create its own working directory and then copy to a final directory when done, which overwrites the existing files each time).

Maybe for now we could add the --time flag as an option in build.sh (I'm thinking maybe build.sh -t to enable it? What do you think?).

I'd also like to start capturing these scripts in the codebase. Maybe we could create a new directory inside cpp/scripts specifically for these build analysis scripts? Something like cpp/scripts/stats? (I'm terrible at naming sometimes)

Since we are specifying the same file for each compiler invocation we are hitting parallel clobber issues due to multiple compiler instances writing to the file at the same time.

If you need a high level overview of what compile jobs have taken so long, and not where in nvcc it has occured. You can scrape the ninja build database for that information. libcudf is doing this already: https://github.com/rapidsai/cudf/blob/branch-23.04/build.sh#L303

Since we are specifying the same file for each compiler invocation we are hitting parallel clobber issues due to multiple compiler instances writing to the file at the same time.

I thought that could be an issue as well, but locally (12 cores) this has not been a problem. To rule it out, is there a way to instruct CMake to make the flag dependent on the output file, e.g., to get --time=CMakeFiles/raft_distance_lib.dir/src/distance/neighbors/ivfpq_search_uint8_t_uint64_t.cu.o.nvcc_log.csv?

Since we are specifying the same file for each compiler invocation we are hitting parallel clobber issues due to multiple compiler instances writing to the file at the same time.

I thought that could be an issue as well, but locally (12 cores) this has not been a problem. To rule it out, is there a way to instruct CMake to make the flag dependent on the output file, e.g., to get --time=CMakeFiles/raft_distance_lib.dir/src/distance/neighbors/ivfpq_search_uint8_t_uint64_t.cu.o.nvcc_log.csv?

There is no easy way to do this. CMake doesn't offer any way to get the object location on a per source basis.

You would need to do something like this:

get_target_property(sources <target_name> SOURCES)
foreach(source IN LISTS sources)
  cmake_path(GET source FILENAME source_name)
  set_source_files_properties(${source} PROPERTIES COMPILE_FLAGS "--time=${source_name}.csv")
endforeach()

@robertmaynard Thanks for the snippet! It works locally.

Since the --time is unlikely to work in general (it is now failing in CI; it may interfere with compile_commands.json), I have made it an optional flag to build.sh as @cjnolet suggested. I have also added a script to analyze the results.

@ahendriksen while it may seem cumbersome, I’ve been thinking about @robertmaynard’s previous suggestion and I actually think it could be useful to dump individual csv files for each of the source files that get compiled.

Though, I wonder, should we stick them in a common directory (maybe something like cpp/build/cuda_time_logs?) I still like the idea of keeping it as an option in build.sh (which ultimately turns on an option in cmake) and I can’t imagine this would add all that much overhead to the build. What we can do is have the script read through all the csv files in the whatever we decide to name that directory.

what do you think?

@cjnolet, One thing that may not be immediately obvious from the suggestion of @robertmaynard is that:

• it creates file names that are equal to the source file name (and thus discards the directory structure)
• we have a dozen files that share the same name.

In summary, with the change you are suggesting, there would still be some translation units that result in writes to the same csv file and we would have to collect all csv files in a directory (as you suggest) to reduce clutter. As such, I think the current design is a local optimum.

@cjnolet, One thing that may not be immediately obvious from the suggestion of @robertmaynard is that:

• it creates file names that are equal to the source file name (and thus discards the directory structure)
• we have a dozen files that share the same name.

In summary, with the change you are suggesting, there would still be some translation units that result in writes to the same csv file and we would have to collect all csv files in a directory (as you suggest) to reduce clutter. As such, I think the current design is a local optimum.

Those are both solvable by computing the relative path of the source file from the root of the project and encoding it into the file name / path.

I thought this was going to be an easy change. The scope is slowly getting out of hand. Maybe we can close the PR and leave it as is for documentation purposes. What do you think @cjnolet?

@ahendriksen I'll leave that up to you. I do think it's a very useful change and it would really help debugging compile times. I agree with @robertmaynard, though, that we should probably capture these timings in individual files. It doesn't seem too hard to accomplish this by taking the path for each file and replacing the / for _. Maybe I'm oversimplifying this though?

@robertmaynard is there an easy way to get a hold of the relative path (from the repo root) for each source file? @ahendriksen I would honestly be happy even if we just dumped the renamed files to a single directory for now.

@ahendriksen I'll leave that up to you. I do think it's a very useful change and it would really help debugging compile times. I agree with @robertmaynard, though, that we should probably capture these timings in individual files. It doesn't seem too hard to accomplish this by taking the path for each file and replacing the / for _. Maybe I'm oversimplifying this though?

@robertmaynard is there an easy way to get a hold of the relative path (from the repo root) for each source file? @ahendriksen I would honestly be happy even if we just dumped the renamed files to a single directory for now.

@cjnolet Here is how you can get the relative path for each source file and convert them into allowable file names:

get_target_property(sources <TARGET> SOURCES)
foreach(source IN LISTS sources)
  cmake_path(IS_ABSOLUTE source is_abs)
  if(is_abs)
    cmake_path(RELATIVE_PATH source BASE_DIRECTORY ${PROJECT_SOURCE_DIR}) # convert to relative path if not already one
  endif()
  string(MAKE_C_IDENTIFIER "${source}" filename) #convert to valid filename
  set_source_files_properties(${source} PROPERTIES COMPILE_FLAGS "--time=${filename}.csv")
endforeach()

I think it might be more difficult than we thought to get this working in CI. I have tried the suggestion writing to separate csv files, but the compilation continues to segfault in CI. A formatted example from the logs:

sccache /opt/conda/conda-bld/_build_env/bin/nvcc -forward-unknown-to-host-compiler [.. snip flags .. ]  \
--time=CMakeFiles/nvcc_log_src_neighbors_refine_d_int64_t_int8_t_cu.csv  \
-MD -MT CMakeFiles/raft_lib.dir/src/neighbors/refine_d_int64_t_int8_t.cu.o \
 -MF CMakeFiles/raft_lib.dir/src/neighbors/refine_d_int64_t_int8_t.cu.o.d -x cu \
-c /opt/conda/conda-bld/work/cpp/src/neighbors/refine_d_int64_t_int8_t.cu \
-o CMakeFiles/raft_lib.dir/src/neighbors/refine_d_int64_t_int8_t.cu.o
nvcc: Segmentation fault

I thought it could have to do with long file names that commonly occur in conda builds, but the paths passed to nvcc are all reasonably short.

If this cannot be made to work in CI, then maybe we should just document that -DCMAKE_CUDA_FLAGS='--time=nvcc_log.csv' will output the log file in one location and the script that is provided in the scripts directory can be used to analyze it (with all the risks for bitrot that that entails).

@robertmaynard do you have any other ideas as to why this might still be causing a segfault in CI.

Im actually a little surprised myself that it's still doing failing.

@ahendriksen Im actually on board w/ keeping this feature as-is for now (outputting to individual files that we can analyze separately) and just not having it run in CI. At least the feature exists that we can run locally to profile the build and we can turn it back on in CI once we figure out what's causing the segault. What do you think? I'd love to have this in 23.04.

@ahendriksen are you sure all the data is being written to the file in that case? I wouldn't normally expect multiple threads / processes to be able to independently write to the same file without some sort of locking mechanism. @robertmaynard do you know if this is the case with nvcc?

@cjnolet : I haven't read the nvcc source code if that is what you mean. I just tested with make -j 200 and 300 single empty-kernel translation units. The resulting csv file still parses and seems to be correct.

I agree with @ahendriksen in testing this nvcc feature does seem to be multi process safe. It most likely does come at some performance cost as each processes takes an exclusive lock on the file.

My only theory on why we are seeing segfaults in CI is that this tracking does incur some memory overhead which is causing a OOM segfault.

@ahendriksen @robertmaynard sounds good to me. If we aren't losing any information, I do agree that it's easier for analysis just to keep everything in the same file.

/merge