短期プロセス追跡

短期プロセス追跡

私のアプリケーションの1つで生成された短期プロセスの動作を理解しようとしています。私が理解したプロセスは次のとおりです。

  1. プロセス名の一部です。
  2. このプロセスを生成するアプリケーションの名前とPID。
  3. おおよそのプロセスが始まる時間です(5〜10分以内)。
  4. プロセスが終了した後のプロセスのPID。

理想的には:

  1. カーネル(または他のもの)がプロセスが開始されたことをスクリプトに通知します。
  2. プロセスに対して複数のツール(iostat、straceなど)を実行します。

プロセスが開始されたことをカーネルに知らせるようにして、私がこれに対処できるようにする方法はありますか?

そんな風に走るのはwhile true; do ps -ef | grep ${MY_PROCESS_NAME}; done酷くてひどいようです。無差別代入検索ではなく、このようなことが発生したときに通知を受け取ることができたらと思います。

それとも、親プロセスとすべての子プロセスに対してこれらのツールを実行してから、後で出力をフィルタリングしますか?たとえば、strace -ff -o ./some.trace -p ${PARENT_PID}

答え1

一度見てみたいかもしれませんモニタリングの実行(カーネルが通常CONFIG_FTRACEで構成されていると仮定します。)これは、Brendan Gregg Tracking and Performance Collectionの多くのスクリプトの1つです。引数がない場合は、起動時にシステム上のすべてのコマンドを表示したり、正規表現を提供して監視できます。

zshたとえば、開始できる既存のコマンドまたは新しいコマンドを見つけるには、次のようにします。

sudo /opt/perf-tools-master/bin/execsnoop zsh

新しいzshを起動すると、次の出力が表示されます。

Tracing exec()s issued by process name "zsh". Ctrl-C to end.
Instrumenting sys_execve
   PID   PPID ARGS
 21920  21919 /usr/libexec/grepconf.sh -c
 21923  21922 /usr/bin/tty -s
 21922  21919 /usr/bin/tput colors
 21924  21919 /usr/bin/dircolors --sh /etc/DIR_COLORS.256color
 21925  21919 /usr/bin/grep -qi ^COLOR.*none /etc/DIR_COLORS.256color
 21926  21919 /usr/libexec/grepconf.sh -c
 21928  21919 /usr/libexec/grepconf.sh -c
 21930  21919 uname -m
 21932  21919 /bin/grep -q /usr/lib64/qt-3.3/bin
 21934  21933 /usr/bin/id -u

実行中のプログラムのフルネームがわかったら、通常はフックを追加してから元のプログラムを実行するスクリプトでファイルを置き換えます。これを行うことができない場合は、同様の方法を使用して、fanotify(7)開いている各ファイルが完了する前にスヌーピングプログラムに介入させることができます。あるいは、プロセスにinotifywatch追加するのに十分な速さがあります。strace

答え2

見てsysdig、システムコールを監視するためのツールです。プロセスを作成するプロセスのpidを知っている場合は、次のことができます。

$ sudo sysdig proc.ppid=<PID>

これは、特定のPIDを持つプロセスに対して親PIDによって実行されたすべてのシステムコールの出力を生成します。ターゲットプログラムのフルネームを知っている場合は、それをフィルタに含めることができます。

$ sudo sysdig proc.ppid=<PID> and proc.name=<NAME>

これは代替に適したものを提供しますstrace。たとえば、上記のコマンドを使用してシェルを監視し、次のコマンドの実行を見つけますls

$ sudo sysdig proc.ppid=18659 and proc.name=ls
9762 16:07:05.911583406 0 ls (20545) < execve res=0 exe=ls args=-F.--color=auto. tid=20545(ls) pid=20545(ls) ptid=18659(zsh) cwd= fdlimit=1024 pgft_maj=0 pgft_min=69 vm_size=452 vm_rss=16 vm_swap=0 comm=ls cgroups=cpuset=/.cpu=/.cpuacct=/.io=/.memory=/.devices=/.freezer=/.net_cls=/.perf_eve... env=LANG=en_US.utf8.USER=user.LOGNAME=user.HOME=/home/user.PATH=/usr/loc... tty=34818 pgid=20545(ls) loginuid=1000
9763 16:07:05.911608835 0 ls (20545) > brk addr=0
9764 16:07:05.911609493 0 ls (20545) < brk res=557E882FF000 vm_size=452 vm_rss=176 vm_swap=0
9765 16:07:05.911652583 0 ls (20545) > access mode=4(R_OK)
9766 16:07:05.911657425 0 ls (20545) < access res=-2(ENOENT) name=/etc/ld.so.preload
9767 16:07:05.911663159 0 ls (20545) > openat
9768 16:07:05.911686542 0 ls (20545) < openat fd=3(<f>/etc/ld.so.cache) dirfd=-100(AT_FDCWD) name=/etc/ld.so.cache flags=4097(O_RDONLY|O_CLOEXEC) mode=0 dev=800
9769 16:07:05.911688872 0 ls (20545) > fstat fd=3(<f>/etc/ld.so.cache)
9770 16:07:05.911690846 0 ls (20545) < fstat res=0
9771 16:07:05.911691850 0 ls (20545) > mmap addr=0 length=44827 prot=1(PROT_READ) flags=2(MAP_PRIVATE) fd=3(<f>/etc/ld.so.cache) offset=0
9772 16:07:05.911694436 0 ls (20545) < mmap res=7FD38EDE7000 vm_size=496 vm_rss=256 vm_swap=0
9773 16:07:05.911695345 0 ls (20545) > close fd=3(<f>/etc/ld.so.cache)
9774 16:07:05.911695808 0 ls (20545) < close res=0
...
11068 16:07:05.913562304 0 ls (20545) > close fd=1(<f>/dev/pts/2)
11069 16:07:05.913562881 0 ls (20545) < close res=0
11070 16:07:05.913564527 0 ls (20545) > close fd=2(<f>/dev/pts/2)
11071 16:07:05.913564857 0 ls (20545) < close res=0
11072 16:07:05.913572008 0 ls (20545) > exit_group
11073 16:07:05.913622981 0 ls (20545) > procexit status=0

あなたは見ることができますユーザーマニュアルフィルタリングとフィルタリングによって生成される情報を設定するための追加オプションを確認してください。これにより、印刷内容をカスタマイズし、スクリプトから対応する出力を読み込んで、必要な他のツールを実行できます。

答え3

straceonと一緒に-f使用されますbash。シェルから短期プログラムを起動します。

実行に0.1秒以上かかるシステムコールの出力をフィルタリングする方法は次のとおりです。 32330は私のシェルのPIDです。私は "read(0") を無視します。なぜなら、これは私のシェルから出て、シェルが入力を待っているので、すでに長い時間がかかるからです。

$ strace -p 32330 -f -T -tt |&
awk '$2 != "read(0," {
    elapsed=$(NF)
    l=length(elapsed)
    elapsed=substr(elapsed,2,l-2)+0
    if (elapsed>0.1) {
        print
    }
}'

sleep 2シェルで実行したときの出力です。

[pid 28454] 17:09:34.271522 nanosleep({2, 0}, NULL) = 0 <2.000138>
17:09:36.271900 <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WSTOPPED|WCONTINUED, NULL) = 28454 <2.002035>

関連情報