1. 32

I do a lot of performance consulting which involves getting up to speed with new code really quickly. This is one of the tools I use to do that very quickly!

  1. 19

    I came expecting to be dazzled, and instead I was only mildly amused. It’s a good tool, and a great idea, but the use of “anything” in the title is only technically correct, not practically correct, and reeks of clickbait. In other words: “for some set of programs that provide verbose printing before and after calls to processes taking time, tss can add timestamps even if the programmer didn’t provide them.”

    I’m unlikely to adopt the use of tss, for my own programs, instead of emitting profiling data myself. But, for unfamiliar programs that happen to have a verbose mode, I can see this being a useful first step in finding issues.

    1. 4

      It’s very clever given the constraint “the SUT might be written in anything”. Many things come with a -v flag.

      The workflow the post discusses sounds like it would involve iteratively putting a few printfs in, seeing which ones have inconveniently large gaps between, adding printfs to whatever happens between, until the gaps between profile lines leave no particularly difficult mysteries.

      I suppose it does implicitly assume a short-ish edit compile run cycle, but that’s true for any workflow based on adding printf calls.

    2. 9
          ls -l> >(while read;do echo $(date +%s%N) $REPLY;done)
      

      Use the redirection. You only need bash and date, and don’t need to worry about pipefail

      1. 8

        Neat. I wrote a Rust version, which involved a bit more yak shaving.

        1. 3

          And it’s now a crate.

          1. 2

            Thanks for that. It felt weird asking for a crate here, so thanks for closing my issue!

        2. 6

          Elegant! The simplicity is really impressive, a real 80/20 kind of solution.

          Maybe you could solve the pipefail thing by having a tts utility that invokes the target program as a subprocess, capturing its stdout+err and then when it stops, wait4() it and return with the same error code the child did.

          1. 4

            Added to rtss - stderr of the child still goes to stderr, so redirection works as you’d expect.

            1. 2

              Nice. ❤

          2. 4

            Pretty neat. The other nearly-universal technique is to attach gdb to the process, and repeatedly stop ask for a backtrace. Works with many interpreted languages like Python or Perl, SQL, C, etc. If you collect 5-10 samples, that’s enough to start with.

            And strace is a quick way to see if it’s blocked on a system call or e.g. repeatedly opening the same file.

            1. 9

              If you have access to DTrace, something like this will save you time:

              dtrace -n ‘profile-5 /pid==475/ { ustack(8) }’

              Prints the bottom eight calls of the stack of PID 475 every 5Hz. Adjust to taste.

              1. 6

                The gdb technique even has a website: http://poormansprofiler.org/ =D

                ( https://gist.github.com/unhammer/4e91821075c2485999eb has some handy tweaks on that for OCaml programs)

              2. 3

                A tool I’ve used that’s pretty great is tj, which has convenient colored output and some more configurable output options. This example with Docker shows a little of what it can do visually.

                1. 2

                  The terminal app iTerm2 for macOS has this feature built-in. Just activate the menu item View > Show Timestamps (⇧⌘E) to display an overlay with the timestamps of every line in history. You don’t even have to turn the feature on before running the command to profile – iTerm2 is always saving past timestamps just in case.

                  1. 0

                    Don’t reach for a profiler, don’t try to set a global variable, or do start/stop timing in code. Don’t even start figuring out how to configure a logger to print timestamps, and use a log output format.

                    Then when you’ve done all this, rerun the command and pass it through a command that attaches timestamps to every output line.

                    That’s some terrible writing. Cool tool, though.

                    1. 1

                      Thank you for reading.