Coarse process profiling, factor out k-util.sh

[ehildenb]

Blocked on #2404

This PR does several things:

• Factors out the handling of all options used in k-util.sh to the k-util.sh file itself. Basically, if an option was used somewhere in k-util.sh, I tried to factor out that option handling into that script. This includes:
  • --verbose
  • --no-exc-wrap
• Corrects the way we use printf "... $@" | ${fold_lines} to use $* instead of $@ ($@ expands to each argument separately when in double-quotes, but $* expands it as part of a single argument, and printf expects a single argument).
• Removes the unused warning function.
• Factors out the help messages for common options into k_util_usage.
• Adds a new coarse-profiling common-option for getting process-level time-spent. This is in service of https://github.com/runtimeverification/algorand-sc-semantics/issues/494 and this type of profiling has been very useful in semantics runner scripts.
• Changes the test for Bison max stack depth option to throw away all output, because the output now contains temporary file names which are not reproducible, and that test is only checking that bison doesn't crash.

[dwightguth]

I would strongly suggest using the time bash primitive rather than what you have here, which will only measure wall time. You can look into the TIMEFORMAT environment variable if you want it to look a certain way.

[ehildenb]

@dwightguth I've made the switch to shell builtin time, but we definitely lose some information that way. In my experience, wall-clock time is a good indication of CPU time if you are profiling correctly anyway (in an isolated way).

That not-withstanding, we lose information about the time between the "major" sub-calls (which are done with execute). With the previous way, printing out a time-delta before and after each command, we see also how much time is spent between each command, which ends up being not insignificant, is what I found.

Should I try to recover this information as well? It would require printing a timestamp before each command is executed I guess.

[radumereuta]

Nice.
I just want some more documentation.

[radumereuta]

lgtm. I'll let you and Dwight decide on the rest of his comments.

[dwightguth]

This seems better, but I still have one minor request. I would also like to see an example of what the output with this flag looks like.

[dwightguth]

This removes the specificity of which component has the error, which I would really like to keep. You can solve this by making it grab the component from an environment variable set by the script that sources this file.

[ehildenb]

Addressed, using variable ktool which the user of k-util.sh is expected to set, and the instructions are updated.

[ehildenb]

Here is some sample output:

0 0:00.01s 0.01s 0.00s kparse --directory . pgm1.teal
0 0:00.01s 0.01s 0.00s llvm-krun -c PGM tmp.in.PGM.G7blEQxQ7L Int korefile --directory /home/dev/src/k/test-kompiled --dry-run -nm -o tmp.in.3cSgbf4koJ
0 0:00.00s 0.00s 0.00s kore-expand-macros ./test-kompiled .krun-2022-01-24-18-32-09-om4v67KlfJ/tmp.in.3cSgbf4koJ
0 0:00.00s 0.00s 0.00s ./test-kompiled/interpreter .krun-2022-01-24-18-32-09-om4v67KlfJ/tmp.in.RMHaPLQpp2 -1 .krun-2022-01-24-18-32-09-om4v67KlfJ/result.kore
<k>
  0 ~> .
</k>
0 0:00.01s 0.01s 0.00s kore-print --directory . --output pretty .krun-2022-01-24-18-32-09-om4v67KlfJ/result.kore --color on

[dwightguth]

I'm not sure how I feel about the text specifying a specific tool rather than being consistent with the format of errors reported by Java code. I would really prefer we keep a uniform experience if possible. But if you think this is a significant improvement, I guess I don't have a huge argument.

I would like to note though that it's possible for the act of sourcing the library script to trigger an error, so we should put the environment variable being set before the source command rather than after.

If you decide you prefer errors with the text they have now, and you address the issue I just mentioned, feel free to merge.

[ehildenb]

I would like to be uniform as well, which k-util.sh will help us achieve. But I do think having the tool name in the error message is an improvement. I've addressed the ktool variable being set before issue.