GraalVMで作ったネイティブイメージを、デバッグしてみたい？

これは、なにをしたくて書いたもの？

先日、GraalVMを使ってJavaアプリケーションをネイティブイメージにして遊んでみました。

GraalVMをインストールして、Javaアプリケーションからネイティブイメージを作って遊ぶ - CLOVER🍀

ところで、こうやってネイティブイメージにしたJavaアプリケーションって、JavaVM上で動いていた時に使っていた
トラブルシュートとかチューニングの話ってどうなるんでしょう？

いろいろ気になるので、いくつか試してみることにしました。

環境

今回の環境は、こちらです。

$ native-image --version
GraalVM Version 1.0.0-rc14

Community Edition。

OSは、Ubuntu Linux 18.04 LTS。

サンプルプログラム

まずは、ネイティブイメージを作るためのサンプルプログラムを作りましょう。

すぐに終了してしまうものを使ってもなんなので、JDKに付属しているHTTPサーバーで簡単なサーバーアプリケーションを
書いてみました。
SimpleHttpServer.java

import java.io.IOException;
import java.net.InetSocketAddress;
import java.nio.charset.StandardCharsets;
import java.time.LocalDateTime;

import com.sun.net.httpserver.HttpServer;

public class SimpleHttpServer {
    public static void main(String... args) throws IOException {
        SimpleHttpServer simpleHttpServer = new SimpleHttpServer();
        simpleHttpServer.start();
    }

    public void start() throws IOException {
        HttpServer server = HttpServer.create(new InetSocketAddress(8080), 0);
        server.createContext("/", exchange -> {
            String requestUri = exchange.getRequestURI().getPath();

            byte[] body;
            switch (requestUri) {
                case "/message":
                    body = "Hello Simple Http Server!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(200, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                case "/error":
                    new RuntimeException("Oops!!").printStackTrace();

                    body = "Server Error".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(500, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                default:
                    body = "Not Found".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(404, body.length);
                    exchange.getResponseBody().write(body);
                    break;
            }
        });

        System.out.printf("[%s] Simple Http Server startup.%n", LocalDateTime.now());

        server.start();
    }
}

アクセスされるURLによってメッセージを返したり、スタックトレースを出力したり、404になったりします。

            switch (requestUri) {
                case "/message":
                    body = "Hello Simple Http Server!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(200, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                case "/error":
                    new RuntimeException("Oops!!").printStackTrace();

                    body = "Server Error".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(500, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                default:
                    body = "Not Found".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(404, body.length);
                    exchange.getResponseBody().write(body);
                    break;
            }

こちらを、コンパイルしてネイティブイメージとしてビルド。

$ javac SimpleHttpServer.java
$ native-image SimpleHttpServer simple-http-server
Build on Server(pid: 10063, port: 43255)
[simple-http-server:10063]    classlist:     208.49 ms
[simple-http-server:10063]        (cap):     786.28 ms
[simple-http-server:10063]        setup:   1,183.20 ms
[simple-http-server:10063]   (typeflow):   4,206.42 ms
[simple-http-server:10063]    (objects):   2,418.49 ms
[simple-http-server:10063]   (features):     137.49 ms
[simple-http-server:10063]     analysis:   6,901.44 ms
[simple-http-server:10063]     universe:     237.28 ms
[simple-http-server:10063]      (parse):     717.83 ms
[simple-http-server:10063]     (inline):     650.98 ms
[simple-http-server:10063]    (compile):   5,282.91 ms
[simple-http-server:10063]      compile:   7,047.21 ms
[simple-http-server:10063]        image:     783.28 ms
[simple-http-server:10063]        write:     197.01 ms
[simple-http-server:10063]      [total]:  16,627.56 ms

とりあえず、起動してみます。

$ ./simple-http-server 
[2019-03-27T22:58:40.253] Simple Http Server startup.

確認。

$ curl localhost:8080/message
Hello Simple Http Server!!

スタックトレース？

まずは、スタックトレースを出力させてみましょう。

$ curl localhost:8080/error
Server Error

サーバー側では、こんなスタックトレースが得られます。

java.lang.RuntimeException: Oops!!
    at SimpleHttpServer.lambda$start$0(SimpleHttpServer.java:27)
    at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)
    at sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:83)
    at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:82)
    at sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:675)
    at com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:79)
    at sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:647)
    at sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:158)
    at sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:431)
    at sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:396)
    at java.lang.Thread.run(Thread.java:748)
    at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:473)
    at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:193)

スタックトレースは、ふつうに得られるんですね。スタックの最初の方は、Substrate VMのもののようですが。

あ、そういえばmainスレッドの方はどうなるんでしょう？こんな感じにして確認してみましょう。

    public static void main(String... args) throws IOException {
        Thread.dumpStack();
        SimpleHttpServer simpleHttpServer = new SimpleHttpServer();
        simpleHttpServer.start();
    }

ふつうでした。

java.lang.Exception: Stack trace
    at java.lang.Thread.dumpStack(Thread.java:1336)
    at SimpleHttpServer.main(SimpleHttpServer.java:10)

では、気を取り直して、別の確認を。

jcmdで見る

先ほどのThread.dumpStackは削除して、ビルド後に再度起動。

jcmdで、Javaプロセスの一覧を見てみます。

$ jcmd
10063 com.oracle.svm.hosted.server.NativeImageBuildServer -port=0 -logFile=$HOME/.native-image/machine-id-c2b8b677f62b47528f9b5c5976abb18f/session-id-1522/server-id-1b3cab2914c3d89a24419e50f7cc776cfaedd8c741bbf195bd2072ec2e0dc2ecbe5b7c5c52eee68a4daa35a5eae31284b77b69413b624e2e3c9fd91e7d82b838/server.log

当然ですが、該当のプロセスはいません。ここで見えているのは、ネイティブイメージをビルドする時に使うデーモンですね。

Thread.printしてみましょう。

$ jcmd [PID] Thread.print
[PID]:
com.sun.tools.attach.AttachNotSupportedException: Unable to open socket file: target process not responding or HotSpot VM not loaded
    at sun.tools.attach.LinuxVirtualMachine.<init>(LinuxVirtualMachine.java:106)
    at sun.tools.attach.LinuxAttachProvider.attachVirtualMachine(LinuxAttachProvider.java:63)
    at com.sun.tools.attach.VirtualMachine.attach(VirtualMachine.java:208)
    at sun.tools.jcmd.JCmd.executeCommandForPid(JCmd.java:147)
    at sun.tools.jcmd.JCmd.main(JCmd.java:131)

スレッドダンプは取れませんね。

また、これを実行すると本体のプログラム側も異常終了してしまいます。

$ ./simple-http-server 
[2019-03-27T23:03:15.096] Simple Http Server startup.
終了 (コアダンプ)

なんということでしょう。

ヒープダンプについては、Enterprise Editionの機能になるみたいですね。

GraalVM also supports monitoring and generating heap dumps of the native image processes. This functionality is available in the Enterprise edition of GraalVM. It is not available in the Community edition of GraalVM.

Generating Heap Dumps

今までのようなJavaアプリケーションでやっていた、ヒープやGCに関するチューニングなどは、ネイティブイメージになると
どういう世界観になるのでしょうねぇ…？

トレースが見たい

話を戻して…実行時にトレースしたければ、straceあたりで追うのがよいのでしょうか？

$ strace -f -tt ./simple-http-server

# もしくは
$ ./simple-http-server
$ sudo strace -f -tt -p [PID]   # 別シェルから

Javaアプリケーションに対してstraceを使う時は、スレッドを追うために「-f」を付与しておくのがよいでしょう。

この状態で、別のターミナルからアクセスしてみます。

$ curl localhost:8080/message

得られたシステムコールのトレース。

[pid 12010] 23:10:41.198685 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:41.198769 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:42.200070 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:42.200282 epoll_wait(7, [{EPOLLIN, {u32=3, u64=5274051511129735171}}], 8192, 1000) = 1
[pid 12010] 23:10:42.385633 accept(3, {sa_family=AF_INET6, sin6_port=htons(33500), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 10
[pid 12010] 23:10:42.385806 fcntl(10, F_GETFL) = 0x2 (flags O_RDWR)
[pid 12010] 23:10:42.385941 getsockname(10, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 0
[pid 12010] 23:10:42.385989 getsockname(10, {sa_family=AF_INET6, sin6_port=htons(8080), inet_pton(AF_INET6, "::ffff:127.0.0.1", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=0}, [28]) = 0
[pid 12010] 23:10:42.386022 fcntl(10, F_GETFL) = 0x2 (flags O_RDWR)
[pid 12010] 23:10:42.386046 fcntl(10, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 12010] 23:10:42.386077 epoll_ctl(7, EPOLL_CTL_ADD, 10, {EPOLLIN, {u32=10, u64=5274051511129735178}}) = 0
[pid 12010] 23:10:42.386107 epoll_wait(7, [{EPOLLIN, {u32=10, u64=5274051511129735178}}], 8192, 0) = 1
[pid 12010] 23:10:42.386141 epoll_wait(7, [{EPOLLIN, {u32=10, u64=5274051511129735178}}], 8192, 1000) = 1
[pid 12010] 23:10:42.386171 fcntl(10, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 12010] 23:10:42.386197 fcntl(10, F_SETFL, O_RDWR) = 0
[pid 12010] 23:10:42.386238 read(10, "GET /message HTTP/1.1\r\nHost: loc"..., 8192) = 85
[pid 12010] 23:10:42.386328 write(10, "HTTP/1.1 200 OK\r\nDate: Wed, 27 M"..., 76) = 76
[pid 12010] 23:10:42.386382 write(10, "Hello Simple Http Server!!", 26) = 26
[pid 12010] 23:10:42.386422 epoll_ctl(7, EPOLL_CTL_DEL, 10, 0x7efc488fec28) = 0
[pid 12010] 23:10:42.386453 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:42.386478 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:43.387748 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:43.387943 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:44.389173 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:44.389290 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:45.390601 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:45.390741 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:46.391927 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:46.392015 epoll_wait(7, [], 8192, 1000) = 0
[pid 12010] 23:10:47.393208 epoll_wait(7, [], 8192, 0) = 0
[pid 12010] 23:10:47.393384 epoll_wait(7,  <unfinished ...>
[pid 12009] 23:10:48.319684 <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out)
[pid 12009] 23:10:48.319793 futex(0x7efc44000c10, FUTEX_WAKE_PRIVATE, 1) = 0
[pid 12009] 23:10:48.319954 futex(0x7efc44000c68, FUTEX_WAIT_PRIVATE, 0, {tv_sec=9, tv_nsec=999998663} <unfinished ...>
[pid 12010] 23:10:48.394623 <... epoll_wait resumed> [], 8192, 1000) = 0

出るには出ましたが、ちょっと遠い感…。

gdb

最後に、gdbで起動、もしくはアタッチしてみます。

gdbから起動。

$ gdb ./simple-http-server
GNU gdb (Ubuntu 8.1-0ubuntu3) 8.1.0.20180409-git
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./simple-http-server...done.
(gdb) run
Starting program: /path/to/simple-http-server 
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff73ff700 (LWP 12241)]
[2019-03-27T23:13:25.369] Simple Http Server startup.
[New Thread 0x7ffff69ff700 (LWP 12242)]

いったん停止するので、「run」で起動させます。

(gdb) run

もしくは、ふつうに起動させて

$ ./simple-http-server 
[2019-03-27T23:14:09.117] Simple Http Server startup.

PIDを指定してアタッチします。

$ sudo gdb -p [PID]

この状態でアクセスすると、gdbで停止させているので応答が返りません。

$ curl localhost:8080/message

スレッドの一覧を表示して

(gdb) info threads
  Id   Target Id         Frame 
* 1    Thread 0x7fe606aad740 (LWP 12274) "simple-http-ser" 0x00007fe6066929f3 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x55daa2b80c7c)
    at ../sysdeps/unix/sysv/linux/futex-internal.h:88
  2    Thread 0x7fe605eff700 (LWP 12275) "server-timer" 0x00007fe606692ed9 in futex_reltimed_wait_cancelable (private=<optimized out>, reltime=0x7fe605efeb50, expected=0, 
    futex_word=0x7fe600000c68) at ../sysdeps/unix/sysv/linux/futex-internal.h:142
  3    Thread 0x7fe6054ff700 (LWP 12276) "Thread-2" 0x00007fe6061adbb7 in epoll_wait (epfd=7, events=0x55daa42f0000, maxevents=8192, timeout=1000)
    at ../sysdeps/unix/sysv/linux/epoll_wait.c:30

リクエストを受け付けてそうなidが3のスレッドに切り替えます。

(gdb) thread 3
[Switching to thread 3 (Thread 0x7fe6054ff700 (LWP 12276))]
#0  0x00007fe6061adbb7 in epoll_wait (epfd=7, events=0x55daa42f0000, maxevents=8192, timeout=1000) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
30  in ../sysdeps/unix/sysv/linux/epoll_wait.c

「next」でステップオーバー実行していけるのですが、デバッグ情報がないので途中までしか終えません…。

(gdb) next
0x000055daa25c3c4f in LinuxNIOSubstitutions$Util_sun_nio_ch_EPollArrayWrapper_iepoll_f76a9091ef4f410ec1627eae0898c2c46c02e2d9 ()
(gdb) next
Single stepping until exit from function LinuxNIOSubstitutions$Util_sun_nio_ch_EPollArrayWrapper_iepoll_f76a9091ef4f410ec1627eae0898c2c46c02e2d9,
which has no line number information.
0x000055daa2818fac in EPollArrayWrapper_epollWait_65c7cd3c240b9db2343c941bc2f6d4961e5cfe4a ()
(gdb) next
Single stepping until exit from function EPollArrayWrapper_epollWait_65c7cd3c240b9db2343c941bc2f6d4961e5cfe4a,
which has no line number information.
0x000055daa2819ece in EPollArrayWrapper_poll_00adcdfdb57d1fdcb4f3215671c0f7bbd6eae172 ()
(gdb) next
Single stepping until exit from function EPollArrayWrapper_poll_00adcdfdb57d1fdcb4f3215671c0f7bbd6eae172,
which has no line number information.
0x000055daa281b231 in EPollSelectorImpl_doSelect_1006e08ca2e2017646cdb058b25c9b24be87c6d3 ()
(gdb) next
Single stepping until exit from function EPollSelectorImpl_doSelect_1006e08ca2e2017646cdb058b25c9b24be87c6d3,
which has no line number information.
0x000055daa2822c55 in SelectorImpl_lockAndDoSelect_c95b627492df0dc902bc7a2692bb39716fab29e5 ()
(gdb) next
Single stepping until exit from function SelectorImpl_lockAndDoSelect_c95b627492df0dc902bc7a2692bb39716fab29e5,
which has no line number information.
0x000055daa2823888 in SelectorImpl_select_dada98992220e20d9b62828bbadebab27a968873 ()
(gdb) next
Single stepping until exit from function SelectorImpl_select_dada98992220e20d9b62828bbadebab27a968873,
which has no line number information.
0x000055daa2807810 in ServerImpl$Dispatcher_run_51b13706a185d0b0496524359e902f86b119d1f8 ()
(gdb) next
Single stepping until exit from function ServerImpl$Dispatcher_run_51b13706a185d0b0496524359e902f86b119d1f8,
which has no line number information.

ここで、プログラムが一気に先に進んでしまいます…。そうですよねぇ。

ちなみに、Enterprise EditionならDWARF（Debug With Arbitrary Record Format ）を含められるらしいですよ。

What tools work with SVM: debugger, profilers? How to use them?

The community version does not support DWARF information. The enterprise version supports all native tools that rely on DWARF information, like debuggers (gdb) and profilers (VTune).

Operational information for native images

デバッグ情報の歩き方 - Qiita

お供は、gdbになるわけですね。

ネイティブイメージをビルドする際のオプションとして、「-g」をつけるとデバッグ情報をつけてくれるというのですが

-g enables debug info generation;

Image Generation Options

Community Editionで「-g」をつけても、そんなオプションは知らないと言われます。

$ native-image -g SimpleHttpServer simple-http-server
Error: Unrecognized option: -g

この機能を使いたかったら、Enterprise Editionで、ということで。

参考）

gcc+gdbによるプログラムのデバッグ 第3回 gdbの便利な機能、デバッグの例

gdbのコマンド一覧

gdbの使い方のメモ - ももいろテクノロジー

自分がコンパイルしていないライブラリの中をGDBで追跡する

gdbの主要コマンド

はじめてのgdb - Qiita

既に起動しているプロセスをgdbで制御する:Geekなぺーじ

gcc+gdbによるプログラムのデバッグ 第1回 ステップ実行、変数の操作、ブレークポイント

オマケ

…で終わってもなんなので、せっかくなのでEnterprise Editionでデバッグビルドしてみましょう。

こちらから、Enterprise EditionのGraalVMをダウンロードしてみます。

Downloads

評価目的では、無料で使えます。

Enterprise EditionのGraalVMになりました。

$ java -version
java version "1.8.0_202"
Java(TM) SE Runtime Environment (build 1.8.0_202-b08)
Java HotSpot(TM) GraalVM EE 1.0.0-rc14 (build 25.202-b08-jvmci-0.56, mixed mode)


$ native-image --version
GraalVM Version 1.0.0-rc14

こうすると「-g」オプションが使えるようになります。

$ native-image -g SimpleHttpServer simple-http-server
Build on Server(pid: 14405, port: 45319)
[simple-http-server:14405]    classlist:     332.47 ms
[simple-http-server:14405]        (cap):     887.73 ms
[simple-http-server:14405]        setup:   1,311.86 ms
[simple-http-server:14405]   (typeflow):   4,824.27 ms
[simple-http-server:14405]    (objects):   3,515.29 ms
[simple-http-server:14405]   (features):     179.57 ms
[simple-http-server:14405]     analysis:   8,670.39 ms
[simple-http-server:14405]     universe:     243.53 ms
[simple-http-server:14405]      (parse):     914.92 ms
[simple-http-server:14405]     (inline):     992.17 ms
[simple-http-server:14405]    (compile):   6,245.03 ms
[simple-http-server:14405]      compile:   8,563.46 ms
[simple-http-server:14405]        image:     781.91 ms
[simple-http-server:14405]    debuginfo:   1,817.51 ms
[simple-http-server:14405]        write:   2,095.36 ms
[simple-http-server:14405]      [total]:  23,874.86 ms

デバッグ情報が生成されました。

[simple-http-server:14405]    debuginfo:   1,817.51 ms

生成されるファイルも、通常のネイティブイメージ以外に、「.debug」が付与されたファイルとソースコードが増えています。

$ find simple-http-server* sources -type f
simple-http-server
simple-http-server.debug
sources/jdk/vm/ci/code/TargetDescription.java
sources/jdk/vm/ci/code/Architecture.java
sources/jdk/vm/ci/amd64/AMD64.java
sources/jdk/vm/ci/meta/MetaUtil.java
sources/jdk/vm/ci/meta/NullConstant.java
sources/jdk/vm/ci/meta/JavaKind.java
sources/jdk/vm/ci/meta/PrimitiveConstant.java
sources/jdk/vm/ci/meta/JavaConstant.java
sources/org/graalvm/nativeimage/c/type/CTypeConversion.java
sources/org/graalvm/nativeimage/UnmanagedMemory.java
sources/org/graalvm/nativeimage/ImageInfo.java
sources/org/graalvm/nativeimage/PinnedObject.java

〜省略〜

sources/java/nio/charset/CoderResult.java
sources/java/nio/charset/UnmappableCharacterException.java
sources/java/nio/charset/CharsetEncoder.java
sources/java/nio/ByteOrder.java
sources/java/beans/PropertyChangeEvent.java
sources/SimpleHttpServer.java

最後に、自分で作成したソースコードが入っています。

では、起動して

$ ./simple-http-server 
[2019-03-27T23:38:30.477] Simple Http Server startup.

gdbでアタッチ。

$ sudo gdb -p [PID]

この時、デバッグ情報が読み込まれたことが表示されます。

of file /path/to/simple-http-server.debug.

では、起動しているアプリケーションにアクセスしてみます。

$ curl localhost:8080/message

スレッドの一覧を見て、スレッドを選択します。

(gdb) info threads
  Id   Target Id         Frame 
* 1    Thread 0x7f0ff2719740 (LWP 15057) "simple-http-ser" 0x00007f0ff22fe9f3 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x7f07f1f86770)
    at ../sysdeps/unix/sysv/linux/futex-internal.h:88
  2    Thread 0x7f07f1cf7700 (LWP 15058) "server-timer" 0x00007f0ff22feed9 in futex_reltimed_wait_cancelable (private=<optimized out>, reltime=0x7f07f1cf6b40, expected=0, 
    futex_word=0x7f07ec000c48) at ../sysdeps/unix/sysv/linux/futex-internal.h:142
  3    Thread 0x7f07f14f6700 (LWP 15059) "Thread-2" 0x00007f0ff1e19bb7 in epoll_wait (epfd=8, events=0x56222709f000, maxevents=8192, timeout=1000)
    at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
(gdb) thread 3
[Switching to thread 3 (Thread 0x7f07f14f6700 (LWP 15059))]
#0  0x00007f0ff1e19bb7 in epoll_wait (epfd=8, events=0x56222709f000, maxevents=8192, timeout=1000) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
30  ../sysdeps/unix/sysv/linux/epoll_wait.c: そのようなファイルやディレクトリはありません.

すると、今度はJavaのソースコード行が見える形でステップ実行できるようになっています。

(gdb) next
34  in ../sysdeps/unix/sysv/linux/epoll_wait.c
(gdb) next
com.oracle.svm.core.posix.linux.LinuxNIOSubstitutions$Util_sun_nio_ch_EPollArrayWrapper.iepoll(int, CStruct com.oracle.svm.core.posix.headers.linux.LinuxEPoll$epoll_event *, int, long) (epfd=8, events=0x56222709f000, numfds=8192, timeout=1000)
    at /path/to/sources/com/oracle/svm/core/posix/linux/LinuxNIOSubstitutions.java:386
386 /path/to/sources/com/oracle/svm/core/posix/linux/LinuxNIOSubstitutions.java: そのようなファイルやディレクトリはありません.
(gdb) next
390 in /path/to/sources/com/oracle/svm/core/posix/linux/LinuxNIOSubstitutions.java
(gdb) next
sun.nio.ch.EPollSelectorImpl.doSelect(java.lang.Object *, long) (AParam0=0x7f07f2002548, JParam1=1000)
    at /path/to/sources/sun/nio/ch/EPollSelectorImpl.java:95
95  /path/to/sources/sun/nio/ch/EPollSelectorImpl.java: そのようなファイルやディレクトリはありません.
(gdb) next
97  in /path/to/sources/sun/nio/ch/EPollSelectorImpl.java

Javaのソースコードは、先ほどデバッグ情報付きで生成したネイティブイメージと一緒に出力された、ソースファイルの位置を
指しています。

では、自分が作ったソースコードにブレークポイントを貼って止めてみましょう。ソースコードの行番号を確認。

$ cat -n SimpleHttpServer.java 
     1  import java.io.IOException;
     2  import java.net.InetSocketAddress;
     3  import java.nio.charset.StandardCharsets;
     4  import java.time.LocalDateTime;
     5  
     6  import com.sun.net.httpserver.HttpServer;
     7  
     8  public class SimpleHttpServer {
     9      public static void main(String... args) throws IOException {
    10          SimpleHttpServer simpleHttpServer = new SimpleHttpServer();
    11          simpleHttpServer.start();
    12      }
    13  
    14      public void start() throws IOException {
    15          HttpServer server = HttpServer.create(new InetSocketAddress(8080), 0);
    16          server.createContext("/", exchange -> {
    17              String requestUri = exchange.getRequestURI().getPath();
    18  
    19              byte[] body;
    20              switch (requestUri) {
    21                  case "/message":
    22                      body = "Hello Simple Http Server!!".getBytes(StandardCharsets.UTF_8);
    23                      exchange.sendResponseHeaders(200, body.length);
    24                      exchange.getResponseBody().write(body);
    25                      break;
    26                  case "/error":
    27                      new RuntimeException("Oops!!").printStackTrace();
    28  
    29                      body = "Server Error".getBytes(StandardCharsets.UTF_8);
    30                      exchange.sendResponseHeaders(500, body.length);
    31                      exchange.getResponseBody().write(body);
    32                      break;
    33                  default:
    34                      body = "Not Found".getBytes(StandardCharsets.UTF_8);
    35                      exchange.sendResponseHeaders(404, body.length);
    36                      exchange.getResponseBody().write(body);
    37                      break;
    38              }
    39          });
    40  
    41          System.out.printf("[%s] Simple Http Server startup.%n", LocalDateTime.now());
    42  
    43          server.start();
    44      }
    45  }

17行目で止めてみます。

    17                String requestUri = exchange.getRequestURI().getPath();

ブレークポイントを設定。

(gdb) break /path/to/sources/SimpleHttpServer.java:17
Breakpoint 1 at 0x5622261f6050: file /path/to/sources/SimpleHttpServer.java, line 17.

Continue。

(gdb) cont
Continuing.

Thread 3 "Thread-2" hit Breakpoint 1, SimpleHttpServer.lambda$start$0(java.lang.Object *) (AParam0=0x7f07f2209780)
    at /path/to/sources/SimpleHttpServer.java:17
17              String requestUri = exchange.getRequestURI().getPath();

指定の場所で止まりました！

スタックトレースを見てみます。

(gdb) bt
#0  SimpleHttpServer.lambda$start$0(java.lang.Object *) (AParam0=0x7f07f2209780) at /path/to/sources/SimpleHttpServer.java:17
#1  0x00005622261f601c in SimpleHttpServer$$Lambda$78003464eaa809674162b25faad5d587da440455.handle(java.lang.Object *, java.lang.Object *) (AParam0=<optimized out>, 
    AParam1=<optimized out>) at /path/to/sources/SimpleHttpServer.java:16
#2  0x000056222626d8b9 in com.sun.net.httpserver.Filter$Chain.doFilter(java.lang.Object *, java.lang.Object *) (AParam0=0x7f07f2209770, AParam1=0x7f07f2209780)
    at /path/to/sources/com/sun/net/httpserver/Filter.java:79
#3  0x000056222626d87e in com.sun.net.httpserver.Filter$Chain.doFilter(java.lang.Object *, java.lang.Object *) (AParam0=0x7f07f2209770, AParam1=0x7f07f2209780)
    at /path/to/sources/sun/net/httpserver/AuthFilter.java:83
#4  0x00005622264853e5 in sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(java.lang.Object *, java.lang.Object *) (AParam0=<optimized out>, AParam1=<optimized out>)
    at /path/to/sources/sun/net/httpserver/ServerImpl.java:675
#5  0x000056222626d8b9 in com.sun.net.httpserver.Filter$Chain.doFilter(java.lang.Object *, java.lang.Object *) (AParam0=0x7f07f2209750, AParam1=0x7f07f2209780)
    at /path/to/sources/com/sun/net/httpserver/Filter.java:79
#6  0x0000562226487298 in sun.net.httpserver.ServerImpl$Exchange.run(java.lang.Object *) (AParam0=0x7f07f22019f8)
    at /path/to/sources/sun/net/httpserver/ServerImpl.java:647
#7  0x0000562226482db6 in sun.net.httpserver.ServerImpl$Dispatcher.handle(java.lang.Object *, java.lang.Object *, java.lang.Object *) (AParam0=0x7f07f2012b20, 
    AParam1=<optimized out>, AParam2=0x7f07f22017c8) at /path/to/sources/sun/net/httpserver/ServerImpl.java:158
#8  0x0000562226483f9f in sun.net.httpserver.ServerImpl$Dispatcher.run(java.lang.Object *) (AParam0=0x7f07f2012b20)
    at /path/to/sources/sun/net/httpserver/ServerImpl.java:396
#9  0x00005622262b39d0 in java.lang.Thread.run(java.lang.Object *) (AParam0=<optimized out>)
    at /path/to/sources/java/lang/Thread.java:748
#10 0x0000562226249b20 in com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(org.graalvm.nativeimage.ObjectHandle) (threadHandle=2)
    at /path/to/sources/com/oracle/svm/core/thread/JavaThreads.java:473
#11 0x00005622262442f2 in com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(RawStructure com.oracle.svm.core.thread.JavaThreads$ThreadStartData *) (
---Type <return> to continue, or q <return> to quit---
    data=<optimized out>) at /path/to/sources/com/oracle/svm/core/posix/thread/PosixJavaThreads.java:193
#12 0x0000562226209900 in com.oracle.svm.core.code.IsolateEnterStub.PosixJavaThreads_pthreadStartRoutine_e1f4a8c0039f8337338252cd8734f63a79b5e3df(long) (JParam0=94704683941104)
    at /path/to/sources/com/oracle/svm/core/code/IsolateEnterStub.java:1
#13 0x00007f0ff22f86db in start_thread (arg=0x7f07f14f6700) at pthread_create.c:463
#14 0x00007f0ff1e1988f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

スタックトレースも見れましたね。

ステップオーバー実行してみます。

(gdb) next
20              switch (requestUri) {
(gdb) next
22                      body = "Hello Simple Http Server!!".getBytes(StandardCharsets.UTF_8);

ローカル変数の値は、見れない…？

(gdb) print requestUri
No symbol "requestUri" in current context.
(gdb) info locals
ALocal0 = <optimized out>
ALocal1 = 0xc
ALocal2 = 0x56222647db70 <sun.net.httpserver.HttpExchangeImpl.sendResponseHeaders(java.lang.Object *, int, long)>
ILocal3 = <optimized out>
ALocal4 = <optimized out>
IStack0 = <optimized out>

どちらにしろ、gdbに関するスキルが足りませんね…。

今回は、こんなところで。また詳しくなったら、再チャレンジしたいですね。