Solarisでgdbがcore-dumpしたので調べてみた

状況の説明

Oracle謹製のSolaris 11.3を利用していて、自前bashをログインシェルにしている状態から、自前gdbを利用したところ以下のようなエラーになりました。

$ gcc -g a.c
$ gdb ./a.out
...
Reading symbols from ./a.out...done.
(gdb) run
Starting program: /home/yasu/tmp/a.out 
[New LWP 2]
[LWP 2 exited]
thread.c:982: internal-error: is_thread_state: Assertion `tp' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
Quit this debugging session? (y or n) y

直接の理由は、デバッグ対象のプログラムをシェル経由で起動する($SHELL -c exec ...)時に,$SHELL内部で生成されたスレッドが期待よりも早く終了し、そのスレッドがデバッグ対象だと思ったgdbがスレッドの内部情報にアクセスしようとしてassertionに失敗する点にありました。

環境

• Solaris 11.3 (amd64)
• gdb 7.11.1 (self-build)
• bash 4.4.11 (self-build)

GNU gdb 7.11.1のビルドメモ

$ env -i PATH=/usr/bin:/bin:/usr/ccs/bin:/usr/gnu/bin/:/usr/gcc/bin CFLAGS=-m64 CXXFLAGS=-m64 LDFLAGS=-m64 ./configure --disable-tui --without-readline --disable-libstdcxx
$ env -i PATH=/usr/bin:/bin:/usr/ccs/bin:/usr/gnu/bin/:/usr/gcc/bin CFLAGS=-m64 CXXFLAGS=-m64 LDFLAGS=-m64 make

最終的にa.outファイルが生成されるので、これをデバッグ対象としてgdbの挙動を確認していきます。

状況が再現するbashのビルドについては最下段の追加調査のセクションに記載しています。

現象の再現

問題になっているのはSHELL変数に格納されているbashに起因するので、上書きすることで挙動が変更できます。

$ cd gdb-7.11.1
$ env -i SHELL=/usr/local/bin/bash gdb/gdb ./a.out
(gdb) run
Starting program: /tmp/tmp.mJkErLWHz0/gdb-7.11.1/a.out 
[New LWP 2]
[LWP 2 exited]
thread.c:982: internal-error: is_thread_state: Assertion `tp' failed.
...

ワークアラウンド1

gdbからrunによってターゲットとなるバイナルを実行する時にSHELLを実行する事が問題であることははっきりしているので、SHELL環境変数からshellを起動しないようにstartup-with-shellオプション(see also - gdb-7.11.1/gdb/inferior.h)を変更します。

gdb

Reading symbols from ./a.out...done.
(gdb) set startup-with-shell off
(gdb) run
Starting program: /tmp/tmp.mJkErLWHz0/gdb-7.11.1/a.out
[Thread debugging using libthread_db enabled]
Hello World
[Inferior 1 (process 16712    ) exited with code 014]

ここでset startup-with-shell onとすることで問題を再現させることができます。

ワークアラウンド2

SHELL変数を問題のない /bin/bash や /bin/csh などを指定してあげれば問題なく動きます。

$ env -i SHELL=/bin/bash gdb/gdb ./a.out

後述するようにSHELL環境変数を使うことで、問題の再現も可能です。

問題が発生している場所

SHELL環境変数を参照しているところはいくつかありますが、gdb/procfs.cの中である事は分かっています。

gdb/procfs.c

static void
procfs_create_inferior (struct target_ops *ops, char *exec_file,
                        char *allargs, char **env, int from_tty)
{
  char *shell_file = "/bin/sh" ; // 問題が発生しない対応例 // original: getenv ("SHELL");
  char *tryname;
  int pid;

trussを使えばトレースできそうだけれど、デバッガとtrussの共存は難しい(JDK-8160350 : cannot truss jdk9 [ solaris ], /proc/self/ctlをデバッガとtrussの両方からopenしようとする際の問題)ので、gdbを使わずtrussだけで正常な/bin/bashと自前bashの実行時の違いをみてみると、気になったのは次のような挙動でした。

$ env -i /usr/bin/truss -f /usr/local/bin/bash -c ls
...
10282:  uucopy(0xFEFFE7C0, 0xFE26EFEC, 20)              = 0
10282:  lwp_create(0xFEFFEA50, LWP_SUSPENDED, 0xFEFFEA4C) = 2
10282/2:        lwp_create()    (returning as new lwp ...)      = 0
10282/1:        lwp_continue(2)                                 = 0
10282/2:        setustack(0xFE1602A0)
10282/2:        schedctl()                                      = 0xFE2A8040
10282/2:        lwp_sigmask(SIG_SETMASK, 0xFFBFFEFF, 0xFFFFFFF7, 0x000000FF, 0x00000000) = 0xFFBFFEFF [0xFFFFF
FFF]
10282/2:        lwp_exit()
10282:  lwp_wait(2, 0xFEFFEC7C)                         = 0
10282:  sysconfig(_CONFIG_PAGESIZE)                     = 4096
...

なぜかlwp_create()が呼ばれていますが、この原因は分かりませんでした。

まとめ

はっきりしませんが、問題は自前bash起動時になぜか生成されるLWP#2をgdbが掴んでしまって、gdbがvfork()したターゲット(a.out)の子プロセス本体を見失う点にあるようにみえます。

別にbashをデフォルトでビルドしてみると、lwp_create()は呼ばれず、SHELL環境変数に設定して問題が再現しないところまでは確認できました。

この後でbashを手元でビルドしたところ、起動時にlwp_create()を呼ぶものができ、SHELL環境変数に指定したところ現象が再現しました。

$ cd bash-4.4.12
$ ./configure --with-libiconv-prefix=/usr/local/gnu --with-libintl-prefix=/usr/local/gnu

追加調査

強引にLWP#1だけをフォローするようにコードを追加すると、無事に実行することができました。
これまた強引にprintf()でevent_ptid.lwpを出力させると、LWP#2が終了した後にevent_ptid.lwpが2であることが分かります。

gdb/fork-child.c

void 
startup_inferior (int ntraps)
{
...
  while (1)
    {
      enum gdb_signal resume_signal = GDB_SIGNAL_0;
      ptid_t event_ptid;

      struct target_waitstatus ws;
      memset (&ws, 0, sizeof (ws));
      event_ptid = target_wait (resume_ptid, &ws, 0);
      if (event_ptid.lwp > 1) event_ptid.lwp = 1; // 追加
...

event_ptid.lwpを1に固定してみると、次のような実行結果が得られました。

実行結果

$ gdb/gdb ./a.out
Reading symbols from ./a.out...done.
(gdb) run
Starting program: /tmp/tmp.mJkErLWHz0/a.out 
[New LWP 2]
[LWP 2 exited]
[Thread debugging using libthread_db enabled]
Hello World
[Inferior 1 (process 7504    ) exited with code 014]

そもそも、このタイミングでLWPが生成されて消滅するのが想定外のように思えます。
考慮する事もいろいろありそうで、根本的な解決策はなかなか難しそうに感じました。

仮にlwpに1を代入せずにパッチを作ると考えると、ws.kindがSPURIOUSな場合にswith_to_thread()を呼び出さずに、そのままbreakする方法でとりあえず回避することはできます。

fork-child.c

      switch (ws.kind)
        { 
          case TARGET_WAITKIND_SPURIOUS:
            break;   // 追加した行
          case TARGET_WAITKIND_LOADED:

gdb-8.2.1での挙動

残念ながらC++対応が進んでいるため、現状ではコンパイルできていません。
ただ gdb/nat/fork-inferior.c にコードが移動している startup_inferior() のコードをチェックする限りでは、同様の問題は引き続き発生すると思われます。

以上