Remix.run Logo
izabera 5 days ago

tested it on this https://github.com/izabera/cube.bash/tree/timep

i ran `source /path/to/timep.bash; timep ./cube.bash "R U R' U' R' F R2 U' R' U' R U R' F'"`

without profiling https://i.imgur.com/JE93ony.png

with profiling there's a bunch of errors but overall it's ~300x slower https://i.imgur.com/qif7Qp3.png so i'm sceptical on all the efficiency claims

jkool702 4 days ago | parent [-]

It took some time, but I figured out what was causing the errors when profiling cube.bash - the code assigns huge (some >400,000 elements) associative arrays in a single command, and timep was taking the full (several MB) $BASH_COMMAND from those and trying to do stuff with it and bash couldnt handle it.

Try profiling cube.bash with the timep version in the "timep_testing" branch (https://github.com/jkool702/timep/blob/timep_testing/timep.b...). This is my "in development" branch that contains a handful of improvements, one of which is that timep will truncate the BASH_COMMAND at 16kb. On my machine at least that timep version successfully profiles cube.bash.

now - regarding efficiency. timep's overhead is more-or-less constant per command (or, more specifically, per debug trap fire). what "percent overhead" this equates to is entirely dependent on how long the average command being profiled takes to run. And for things like base.cube, that are virtually all builtin commands that dont fork, that time is low. For cube.bash it is really pretty remarkably low.

Looking at the "full" profile and stack trace that timep generated, running cube.bash involved running around 7150 commands. I also profiled a modified version that stops at the ` echo scramble: "$@"` line - that one was about 3350 commands. Meaning the timed part of cube.bash (where it actually solves the cube) represents about 3800 bash commands. This part of the code (when run by timep) took 870 ms or so on my system. which puts the per-command overhead at under 1/4 of 1 ms (about 230 microseconds to be precise).

230 microseconds per command is best-in-class for a trap-based profiler - many take an order of magnitude (or more) longer and dont collect cpu times or the code structure metadata needed to reconstruct the full call stack. To put it in perspective, bash (on my system at least) has 1-2 ms overhead every time it runs an external binary. Your cube.bash is just impressively stupidly fast, so much so that the 230 microseconds still introduces considerable overhead.

izabera 4 days ago | parent [-]

thanks for taking the time to make it work on my code :)

jkool702 3 days ago | parent [-]

no problem. thanks for helping me discover and fix a bug in timep that all my test cases missed.

Sorry the overhead is too high (relative to cube.bash's insanely low avg command runtime of something like 1 microsecond) to be really useful as a profiler...hopefully itll still prove useful strictly for mapping the code execution/structure and seeing how many times a given function got called and things of that nature.