exec: measure execution times

* todo: blerc: new bleopts
* todo: ChangeLog
* todo: contrib README.md

README-ja_JP.md

@@ -324,6 +324,13 @@ bleopt prompt_eol_mark='⏎'
 bleopt exec_errexit_mark=
 # Tip: 代わりに他の文字列をご指定頂くこともできます。
 bleopt exec_errexit_mark=$'\e[91m[error %d]\e[m'
+
+# コマンド実行時間マーカー "[ble: elapsed 1.203s (CPU 0.4%)]" の無効化
+bleopt exec_elapsed_mark=
+# Tip: 代わりに別の文字列をご指定いただくこともできます。
+bleopt exec_elapsed_mark=$'\e[94m[%ss (%s %%)]\e[m'
+# Tip: マーカーを表示する条件を変更することも可能です。
+bleopt exec_elapsed_enabled='sys+usr>=10*60*1000' # 例: 合計CPU時間が 10 分以上の時に表示
 ```
 
 ## 2.3 曖昧文字幅

README.md

@@ -302,6 +302,13 @@ bleopt prompt_eol_mark='⏎'
 bleopt exec_errexit_mark=
 # Tip: you may instead specify another string:
 bleopt exec_errexit_mark=$'\e[91m[error %d]\e[m'
+
+# Disable elapsed-time marker like "[ble: elapsed 1.203s (CPU 0.4%)]"
+bleopt exec_elapsed_mark=
+# Tip: you may instead specify another string
+bleopt exec_elapsed_mark=$'\e[94m[%ss (%s %%)]\e[m'
+# Tip: you may instead change the threshold of showing the mark
+bleopt exec_elapsed_enabled='sys+usr>=10*60*1000' # e.g. ten minutes for total CPU usage
 ```
 
 ## 2.3 CJK Width

blerc

@@ -212,6 +212,25 @@
 #bleopt exec_errexit_mark=$'\e[91m[ble: exit %d]\e[m'
 
 
+## "exec_elapsed_mark" specifies the format of the command execution time
+## report.  It takes two arguments: the first is the string that explains the
+## elapsed time, and the second is a number that represents the percentage of
+## CPU core usage.  "exec_elapsed_enabled" specifies the condition that the
+## command execution time report is displayed after the command execution.  The
+## condition is expressed by an arithmetic expression, where a non-zero result
+## causes displaying the report.  In the arithmetic expression, variables
+## "real", "{usr,sys}{,_self,_child}", and "cpu" can be used.  "real"
+## represents the elapsed time.  "usr" and "sys" represent the user and system
+## time, respectively.  The suffixes "_self" and "_child" represent the part
+## consumed in the main shell process and the other child processes including
+## subshells and external programs, respectively.  "cpu" represents the
+## percentage of the CPU core usage in integer, which can be calculated by
+## "(usr+sys)*100/real".  The other values are all in unit of milliseconds.
+
+#bleopt/declare -v exec_elapsed_mark $'\e[94m[ble: elapsed %s (CPU %s%%)]\e[m'
+#bleopt/declare -v exec_elapsed_enabled 'usr+sys>=10000'
+
+
 ## The following setting controls the exit when jobs are remaining. When an
 ## empty string is set, the shell will never exit with remaining jobs through
 ## widgets. When an non-empty value is set, the shell will exit when exit is

docs/ChangeLog.md

@@ -82,13 +82,14 @@
 - menu (menu-style:desc): support multicolumns (motivated by Shahabaz-Bagwan) `#D1686` 231dc39
   - menu (menu-style:desc): fix not working `bleopt menu_desc_multicolumn_width=` `#D1727` 2140d1e
 - term: let <kbd>DECSCUSR</kbd> pass through terminal multiplexers (motivated by cmplstofB) `#D1697` a3349e4
-  - util: refactor `_ble_term_TERM` `#D1746` 0000000
+  - util: refactor `_ble_term_TERM` `#D1746` 63fba6b
 - complete: requote for more compact representations on full completions `#D1700` a1859b6
 - complete: improve support for `declare` and `[[ ... ]]` `#D1701` da38404
   - syntax: fix completion and highlighting of `declare` with assignment arguments `#D1704` `#D1705` e12bae4
   - cmdspec: refactor `{mandb => cmdspec}_opts` `#D1706` `#D1707` 0786e92
 - complete (menu-style:align): refactor `complete_menu_align => menu_align_{min,max}` (motivated by banoris) `#D1717` 22a2449
-- prompt: support `bleopt prompt_command_changes_layout` `#D1750` 0000000
+- prompt: support `bleopt prompt_command_changes_layout` `#D1750` e199bee
+- exec: measure execution times `#D1756` 0000000
 
 ## Changes
 
@@ -137,8 +138,8 @@
 - highlight (`wtype=CTX_CMDI`): check alias names before shell expansions `#D1715` d6242a7
   - util (`ble/is-alias`): fix a bug of unredirected error messages for bash-3.2 (fixup d6242a7) `#D1730` 31372cb
 - edit (`history_share`): update history on `discard-line` (reported by SuperSandro2000) `#D1742` 8dbefe0
-- canvas: do not insert explicit newlines on line folding if possible (reported by banoris) `#D1745` 02b9da6 0000000
-- edit (`ble-bind -x`): preserve multiline prompts on execution of `bind -x` commands `#D1755` 0000000
+- canvas: do not insert explicit newlines on line folding if possible (reported by banoris) `#D1745` 02b9da6 dc3827b
+- edit (`ble-bind -x`): preserve multiline prompts on execution of `bind -x` commands (requested by SuperSandro2000) `#D1755` 7d05a28
 
 ## Fixes
 
@@ -295,15 +296,15 @@
 - menu (`menu-style:desc`): work around xenl quirks for relative cursor movements (reported by telometto) `#D1728` 3e136a6
 - global: work around the arithmetic syntax error of `10#` in Bash-5.1 `#D1734` 7545ea3
 - global: adjust implementations for Bash 5.2 `patsub_replacement` `#D1738` 4590997
-  - global: work around compat42 quoting of "${v/pat/"$rep"}" `#D1751` 0000000
-  - prompt: fix a bug of ble/prompt/print redundantly quoting '$' `#D1752` 0000000
-  - global: identify bash-4.2 bug that internal quoting of `${v/%$empty/"$rep"}` remains `#D1753` 0000000
-  - global: work around `shopt -s compat42` `#D1754` 0000000
+  - global: work around `compat42` quoting of `"${v/pat/"$rep"}"` `#D1751` a75bb25
+  - prompt: fix a bug of `ble/prompt/print` redundantly quoting `$` `#D1752` a75bb25
+  - global: identify bash-4.2 bug that internal quoting of `${v/%$empty/"$rep"}` remains `#D1753` a75bb25
+  - global: work around `shopt -s compat42` `#D1754` a75bb25
 - global (`ble/builtin/*`): work around `set -eu` in NixOS initialization (reported by SuperSandro2000) `#D1743` 001c595
 - util, edit, contrib: add support for `bash-preexec` (motivated by SuperSandro2000) `#D1744` e85f52c
-- main: check `IN_NIX_SHELL` to inactivate ble.sh in nix-shell `#D1747` 0000000
-- canvas: test the terminal for the sequence of clearing `DECSTBM` `#D1748` 0000000
-- main: check `/dev/tty` on startup (reported by andychu) `#D1749` 0000000
+- main: check `IN_NIX_SHELL` to inactivate ble.sh in nix-shell (suggested by SuperSandro2000) `#D1747` b4bd955
+- canvas: test the terminal for the sequence of clearing `DECSTBM` `#D1748` 4b1601d
+- main: check `/dev/tty` on startup (reported by andychu) `#D1749` 711c69f
 
 ## Internal changes and fixes
 

note.txt

@@ -1350,6 +1350,7 @@ bash_tips
 
     2022-01-23
 
+    683 にも unresolved patch suggestion がある。
     https://github.com/scop/bash-completion/pull/687#discussion_r790203991 : IFS=$'\0' in mount
     https://github.com/scop/bash-completion/pull/687#discussion_r790203132 : mechanism of save/restore shopt
 
@@ -1731,8 +1732,51 @@ bash_tips
     ToDo
 -------------------------------------------------------------------------------
 
+2022-01-31
+
+  * rsync --no-while-f[TAB] で説明が一緒に挿入されてしまう。DATA を挿入している
+    のだろうか。。或いは、単一確定の場合に postprocess が走っていなくて直接補完
+    されている。後で確認する必要がある。
+
+  * bash-completion _services が failglob で問題を起こしてい
+    る。_comp_init_set_up_service_completions も駄目。うーん。failglob ではある
+    がこれは自分が修正している途中の物ではない新しい物だろうか? →これは既に
+    fix-failglob　の中に含まれていた。
+
 2022-01-23
 
+  * コマンドのログ機能を作成する。
+
+    特定のファイルに情報を書き込む。
+
+    同時に複数の書き込みがあった場合に混ざり合う危険性がある。滅多に起こらない
+    と思いたいがちゃんと防止策は作っておく必要がある。例えばシェル毎に履歴を記
+    録して終了する時に合成するという手が考えられる。合成自体が衝突する自体を防
+    ぐために mkdir/rmdir を使うのが一つの手である。
+
+    コマンドにはコマンド実行前とコマンド実行後の二つに分けて結果を書き込みたい
+    という欲求がある。という事を考えると、
+
+    $ printf '%x/%s/%s.e%s\n' $(printf '%(%s)T' -1) "$HOSTNAME" $$ "$LINENO"
+
+    * バックグラウンドのジョブの状態はどの様に記録するのか。うーん。ジョブに関
+      しては一応 ble.sh の中で追跡はしている。それに従って終端を幾らか荒い尺度
+      で検出する事はできる。しかし正確な時間は分からない。
+
+      プロンプトを表示した時刻も記録しておくと良い様に思われる。しかしそうなる
+      と大量の記録が残ってしまう事になるのではないか。うーん。プロンプトを表示
+      した時刻に関しては別に全てを記録する必要はない。前回のプロンプトの表示時
+      刻だけ覚えておいて、ジョブ変化を検出した時にその情報を備考として乗せるだ
+      けで良いのである。
+
+    * 記録する情報は以下の通り。
+
+      cmd, pwd, 終了ステータス(PIPESTATUS), 各種時刻情報, files(自動補完用), 構
+      文解析情報(後で単語を抽出する為。というか単語の範囲だけで良い).
+
+      これを使って処理するのはもしかしたら外部プログラムに頼らなければならない
+      かもしれない。
+
   * 元々存在した DEBUG trap を保持する
 
   * bash-preexec に API 安定化のお願いをする。
@@ -5900,6 +5944,68 @@ bash_tips
 
 2022-01-24
 
+  * edit: コマンド実行時間計測 [#D1756]
+
+    前から気になっていたので実装する。
+
+    * time を用いた計測? 少なくとも msec の精度は存在する。prologue にかかる時
+      間などは気になるが。prologue は含めずに計測するのが良いだろう。
+
+
+      現在の gexec の構造を何処まで変更できるかについて確認しなければならない。
+      現在の構造に修正したのは 014d17e6 (#D0465)である。うーん。eval を跨ぐと
+      $_ が継承されない? と思ったが prologue に関しては同じ eval に入れなくても
+      大丈夫に見える。以下のコマンドを各 bash version で試したがちゃんと動いて
+      いる。
+
+      $ { echo hello world; time builtin eval 'echo "[$_]"'; echo $_; }
+
+      うーん。分かった。prologue を同じ eval の中に入れるのは set -v の時の出力
+      を最低限に抑える為である → 書き換えた。一応ちゃんと $_ 及び $? が復元で
+      きている事を確かめた。
+
+    うーん。ble/util/clock だとか ble/bin/date +%s%6N だとかに頼る方法を考えて
+    いたが、time の結果を読み取っている現状では tot をそのまま参照すれば良い気
+    がする。開始時刻に関しては date または printf または SECONDS を用いて取得す
+    れば良い → 最終的にはやはり ble/util/clock または date +%s%6N に頼る事にし
+    た。それを tot を用いて補正する。
+
+    * SECONDS, EPOCHREALTIME, EPOCHSECONDS を readonly するという事? EPOCH* に
+      ついては流石に間違えて上書きしたりする事はないと思われる。SECONDS は
+      ble/util/clock の初期化時に readonly する事にした。EPOCHSECONDS はどうせ
+      使っていないので関係ない。
+
+    * done: カスタマイズインターフェイスについて考えた方が良い気がする。現状で
+      既存の errexit とどうくっつけるのかというのが問題である。というより、本当
+      は色分けをしたりしたい所だが、現状 errexit の設計が固定文字列になっている
+      ので、勝手に弄る余地がなくなってしまっている。
+
+      或いは既定値の時にはくっつけるという操作をするというのでも良いかもしれな
+      い? と思ったがそれも変である。或いは、もっと別枠の設定を用意するというの
+      も手なのかもしれない→うーん。両方とも無効化して自前で書くというのが良い
+      気がする。という事を考えたら、現状では exec_errexit_mark と同様に
+      exec_elapsed_mark を定義すれば良い。
+
+    * done: contrib README.md
+    * done: ChangeLog
+    * done: blerc: new bleopts
+    * done: wiki: new bleopts
+
+    x 外部コマンドの時間が計れていない? と思ったが単に cxxmatrix に対して端末が
+      遅いだけなのであった。多分測れている。子シェルを合計するかしないかの設定
+      があった気がしたけれど、それは多分 times であって関係ないのだ。一応 times
+      を使えば real 及び sys の子プロセスの内訳も見られる気がする…が BG で動い
+      ている物が加算されるのかは謎である。
+
+      →うーん。times はジョブが終了した瞬間に加算されるので、bg のジョブが丁度
+      終了したりすると、現在実行しているコマンドの shell/sys の値を評価できなく
+      なる。そもそも time で取れている情報の筈なので関係ない気もする。。と思っ
+      たが、シェル本体と子プロセスの時間を区別するのには使えるのかもしれない。
+      つまり自プロセスの処理時間を取得するのには使える。
+
+    x EOF marker が動かなくなっている。確認する必要がある。と思ったがこれは単純
+      に 2 が /dev/null に繋がっていたというだけの話だった。OK
+
   * edit: bind -x 関数の呼び出しに際しての画面クリアの振る舞いについて (motivated by SuperSandro2000) [#D1755]
     https://github.com/akinomyoga/blesh-contrib/issues/6#issuecomment-1020165711