1. 5
    Tracing Execution in Oil (set -x /xtrace) programming unix oilshell.org
    andyc avatar authored by andyc 2 years ago |
    Archive.org Archive.today Ghostarchive
    | 9 comments
    1. 3
      andyc avatar andyc Oil Shell Developer 2 years ago | link

      I’m looking for feedback on this – is it comprehensible / useful? It will probably take a few moments to figure out, but once you do, I think it should scale to large shell programs, and has many advantages over shell tracing.

      More examples here:

      https://oilshell.zulipchat.com/#narrow/stream/121540-oil-discuss/topic/xtrace_rich.20.3A.20Oil's.20enhanced.20tracing

      (requires login, feel free to chat with me about it) Also note this is NOT released yet, but you can build it from the repo if you want. I can help

      Another good example:

      $ bin/osh -O oil:basic -x -c 'echo foo; sleep 0.1 & sleep 0.2 & echo bar; wait'
. builtin echo foo
foo
| fork 31218
  . 31218 exec sleep 0.1
| fork 31219
. builtin echo bar
bar
  . 31219 exec sleep 0.2
> wait
  ; process 31218: status 0
  ; process 31219: status 0
< wait
      1. 2
        Pentlander avatar Pentlander 2 years ago | link

        That is pretty nice, I usually debug shell scripts using echo statements. Tbh I completely forget about the trace setting most of the time.

        1. 1
          andyc avatar andyc 2 years ago | link

          Yeah the tracing in bash is “OK”, I use it reluctantly…

          I think this is a lot better and could lead to more tools on top! The format should be parseable so many it can be visualized with timing. Could be useful for big continuous builds.

          It will be out soon! Let me know if you have other feedback

        2. 1
          ilyash avatar ilyash 2 years ago | link

          In NGS this could be debug("blah") or debug("myfacility", "blah") which you could leave in and turn on and off with the DEBUG environment variable. The output of debug() goes to standard error, yet another convenience over bash where you should redirect the output of echo.

          1. 1
            andyc avatar andyc 2 years ago | link

            In bash I just do this, then use it like log "x = $x".

            log() {
  echo "$@" >&2
}

            You can also wrap that in if test -z "$DEBUG", etc.

            This might be built in to Oil, i.e. https://github.com/oilshell/oil/issues/750

            1. 1
              ilyash avatar ilyash 2 years ago | link

              In bash I just do this

              On top of many scripts. That’s why I moved this to standard library. It’s just common.

              You can also wrap that in if test -z “$DEBUG”, etc

              Again, I find it’s common enough to deserve to be in standard library.

    2. 1
      ilyash avatar ilyash 2 years ago | link

      Looks like this is yet another feature which highlights our difference in approaches. Oil is heavily rooted in the shell world. Next Generation Shell tries first to be a programming language. Oil has set -x while NGS went with DEBUG environment variable, modelled after https://www.npmjs.com/package/debug ( DEBUG has comma separated facilities to trace, * for everything).

      It is interesting to see how both projects trying to solve mostly same problems but in different ways.

      1. 1
        andyc avatar andyc edited 2 years ago | link

        I don’t think debug() is quite the same thing, because you have to insert those statements right? This kind of tracing doesn’t use any annotations.

        Does NGS have a tracer that logs every process start and exit, with PID and status? i.e. every component in a pipeline? That would be the equivalent to this.

        (Whether it looks like set -x or DEBUG=1 seems like a cosmetic issue. The idiomatic to write it in Oil is shopt --set xtrace , or shopt --set oil:basic xtrace, but the shell style is supported too.)

        1. 1
          ilyash avatar ilyash 2 years ago | link

          I don’t think debug() is quite the same thing, because you have to insert those statements right?

          Yes, you have to insert the statements. On the other hand standard library which handles running external processes already has these debug()s.

          Does NGS have a tracer that logs every process start and exit, with PID and status?

          Yes:

          $ DEBUG=process ngs -e '$(ls | wc -l)'
[DEBUG process 237725 main] Parsed command: [ls]
[DEBUG process 237725 main] [find_in_path] got ls
[DEBUG process 237725 main] [find_in_path] will search
[DEBUG process 237725 main] [find_in_path] ls found at <Path path=/usr/bin/ls>
[DEBUG process 237725 main] PID after fork: 237733
[DEBUG process 237733 main] PID after fork: 0
[DEBUG process 237725 main] Reading all output of the child process
[DEBUG process 237725 main] Parsed command: [wc,-l]
[DEBUG process 237733 main] will execve()
[DEBUG process 237725 main] [find_in_path] got wc
[DEBUG process 237725 main] [find_in_path] will search
[DEBUG process 237725 main] [find_in_path] wc found at <Path path=/usr/bin/wc>
[DEBUG process 237725 main] PID after fork: 237734
[DEBUG process 237734 main] PID after fork: 0
[DEBUG process 237725 main] Reading all output of the child process
[DEBUG process 237725 main] Creating thread process-237734-output-fd-1-reader
[DEBUG process 237725 process-237734-output-fd-1-reader] Thread set up done, will run thread code
[DEBUG process 237725 main] [wait] joining reading and writing threads
[DEBUG process 237725 main] [wait] will waitpid(237733)
[DEBUG process 237725 main] [wait] waitpid(237733) -> [237733,0]
[DEBUG process 237725 main] [wait] joining reading and writing threads
[DEBUG process 237725 main] Joining thread <Thread process-237734-output-fd-1-reader>
[DEBUG process 237734 main] will execve()
[DEBUG process 237725 process-237734-output-fd-1-reader] Read all output of the child process for descriptor 1, closing reading/parent end
[DEBUG process 237725 main] [wait] will waitpid(237734)
[DEBUG process 237725 main] [wait] waitpid(237734) -> [237734,0]

          I think the output of Oil’s set -x is more elegant.

          Whether it looks like set -x or DEBUG=1

          Except that it’s DEBUG=facility1,facility2,... or DEBUG=*, which gives more flexibility.