サンプルコードで身につける: JVM は何を読んで実行するのか

解説で学んだ概念を、5つの具体例で確認します。素朴な例から実務寄りの例へと進みます。

1java が開いたファイルを順に記録する

というツールで、コマンドが OS に頼んだ「実行」と「ファイルを開く」を記録したものです。execve(実行)は先頭の1行だけで、あとは openat(開く)と write(出力)です。Hello.class を開いた後に step 1 が出力され、その後で初めて Helper.class が開かれています。下の2行は読み込んだ中身で、先頭の \312\376\272\276 はを8進数で表したものです。

$ strace で記録した java -cp out com.example.demo.Hello(共有ライブラリや設定ファイルなどの行を除き、各行を短くした抜粋。行頭はスレッド ID)追跡ログ

126   execve("/opt/java/openjdk/bin/java", ["java", "-cp", "out", "com.example.demo.Hello"], ...) = 0
126   openat("/opt/java/openjdk/bin/../lib/libjli.so", O_RDONLY|O_CLOEXEC) = 3
126   openat("/opt/java/openjdk/lib/jvm.cfg", O_RDONLY) = 3
126   openat("/opt/java/openjdk/lib/server/libjvm.so", O_RDONLY|O_CLOEXEC) = 3
127   openat("/opt/java/openjdk/lib/libjimage.so", O_RDONLY|O_CLOEXEC) = 3
127   openat("/opt/java/openjdk/lib/modules", O_RDONLY) = 3
127   openat("/opt/java/openjdk/lib/libjava.so", O_RDONLY|O_CLOEXEC) = 4
127   openat("/opt/java/openjdk/lib/server/classes.jsa", O_RDONLY|O_CLOEXEC) = 4
127   openat("/w/out/com/example/demo/Hello.class", O_RDONLY) = 4
127   write(1, "step 1: main started (Helper not"..., 43) = 43
127   openat("/w/out/com/example/demo/Helper.class", O_RDONLY) = 4
127   write(1, "step 2: hello, JVM\n", 19) = 19
 
read(4</w/out/com/example/demo/Hello.class>, "\312\376\272\276\0\0\0E\0007\n\0\2\0\3\7\0\4\f\0\5\0\6\1\0\20java/l"..., 1000) = 1000
read(4</w/out/com/example/demo/Helper.class>, "\312\376\272\276\0\0\0E\0!\n\0\2\0\3\7\0\4\f\0\5\0\6\1\0\20java/l"..., 710) = 710

2JVM 自身に、どのクラスをどこから読んだかを言わせる

java にを付けると、読み込んだと出どころが1行ずつ出ます。この実行ではクラスの行が 607 あり、そのうち 602 は shared objects file( に付属する)からで、自分のフォルダ out から読んだのは Hello と Helper の2つだけでした。でアーカイブを切ると、の出どころは jrt:/java.base( の中)に変わります。

$ java -Xlog:class+load ...(... は省略した行。先頭の時刻は実行ごとに変わる)コマンド出力

$ java -Xlog:class+load -cp out com.example.demo.Hello
[0.003s][info][class,load] java.lang.Object source: shared objects file
[0.003s][info][class,load] java.lang.String source: shared objects file
  ...
[0.015s][info][class,load] com.example.demo.Hello source: file:/w/out/
step 1: main started (Helper not used yet)
[0.015s][info][class,load] com.example.demo.Helper source: file:/w/out/
  ...
step 2: hello, JVM
 
$ java -Xshare:off -Xlog:class+load -cp out com.example.demo.Hello
[0.002s][info][class,load] java.lang.Object source: jrt:/java.base
[0.002s][info][class,load] java.lang.String source: jrt:/java.base

3JAR から読む場合: 開き直さずに、必要な項目へ移動して読む

同じ2クラスを app.jar にまとめてで起動したときの記録です。app.jar は2回開かれます。1回目は java コマンドが( の中の設定ファイル。入口のクラス名が書いてある)を読んですぐ閉じ、2回目はが開いて、以後は閉じません。Hello の項目を読んで step 1 を出力した後、lseek(読む位置の移動)で Helper の項目へ移動して読んでいます。

$ strace で記録した java -jar app.jar(app.jar に関する行の抜粋。... は省略した行、# 以降は補足)追跡ログ

270   execve("/opt/java/openjdk/bin/java", ["java", "-jar", "app.jar"], ...) = 0
270   openat(AT_FDCWD</w>, "app.jar", O_RDONLY) = 3</w/app.jar>          # 1回目: java コマンド
270   lseek(3</w/app.jar>, -22, SEEK_END) = 1893
270   read(3</w/app.jar>, "PK\5\6\0\0\0\0\7\0\7\0\275\1\0\0\250\5\0\0\0\0", 22) = 22
      ...
270   lseek(3</w/app.jar>, 93, SEEK_SET) = 93
270   read(3</w/app.jar>, "\5\301\261\n\0021\f..."..., 100) = 100              # MANIFEST.MF(圧縮後 100 B)
270   close(3</w/app.jar>)              = 0
      ...                                                                 # この間に lib/modules と classes.jsa を開く
271   openat(AT_FDCWD</w>, "app.jar", O_RDONLY) = 4</w/app.jar>          # 2回目: JVM。以後 close しない
      ...
271   lseek(4</w/app.jar>, 332, SEEK_SET) = 332
271   read(4</w/app.jar>, "PK\3\4\24\0\10\10\10\0..."..., 30) = 30
271   lseek(4</w/app.jar>, 390, SEEK_SET) = 390
271   read(4</w/app.jar>, "\215SmO\323P\24~..."..., 560) = 560                # Hello.class の項目
271   write(1<pipe:[12698]>, "step 1: main started (Helper not"..., 43) = 43
271   lseek(4</w/app.jar>, 966, SEEK_SET) = 966
271   read(4</w/app.jar>, "PK\3\4\24\0\10\10\10\0..."..., 30) = 30
271   lseek(4</w/app.jar>, 1025, SEEK_SET) = 1025
271   read(4</w/app.jar>, "\215R\333N\0331\20=CH6..."..., 407) = 407          # Helper.class の項目
271   write(1<pipe:[12698]>, "step 2: hello, JVM\n", 19) = 19

4同じことを Node で: 読むのはテキスト

同じ形のプログラムを Node(v24.21.0)で動かして記録したものです。OS が実行したのは node だけで、main.js は開いて読まれるテキストです。require の場合、helper.js は step 1 の出力の後、その行に来てから開かれました。ES のに書き換えた版では、step 1 より前に両方のファイルが開かれています。

$ strace で記録した node main.js と node main.mjs(共有ライブラリなどの行を除いた抜粋。# の行は補足)追跡ログ

# node main.js(require)
40    execve("/usr/local/bin/node", ["node", "main.js"], 0xffffce2b0d28 /* 6 vars */) = 0
40    openat(AT_FDCWD</w>, "/w/package.json", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
40    openat(AT_FDCWD</w>, "/w/main.js", O_RDONLY|O_CLOEXEC) = 17</w/main.js>
40    write(1<pipe:[12075]>, "step 1: main started (helper not"..., 47) = 47
40    openat(AT_FDCWD</w>, "/w/helper.js", O_RDONLY|O_CLOEXEC) = 18</w/helper.js>
40    write(1<pipe:[12075]>, "step 2: hello, V8\n", 18) = 18
 
read(17</w/main.js>, "console.log('step 1: main starte"..., 8192) = 148
read(18</w/helper.js>, "exports.greet = (who) => 'hello,"..., 8192) = 42
 
# node main.mjs(import { greet } from './helper.mjs')
84    openat(AT_FDCWD</w>, "/w/main.mjs", O_RDONLY|O_CLOEXEC) = 17</w/main.mjs>
84    openat(AT_FDCWD</w>, "/w/helper.mjs", O_RDONLY|O_CLOEXEC) = 17</w/helper.mjs>
84    write(1<pipe:[12075]>, "step 1: main started\n", 21) = 21
84    write(1<pipe:[12075]>, "step 2: hello, V8\n", 18) = 18

// main.js(CommonJS)
console.log('step 1: main started (helper not required yet)');
const helper = require('./helper.js');   // この行に来てから helper.js が開かれた
console.log('step 2: ' + helper.greet('V8'));

// helper.js
// exports.greet = (who) => 'hello, ' + who;

5V8 が実行時に中で作るバイトコード

Node にデバッグ用のフラグを付けると、がソースから作ったを表示できます。helper.js の1行の関数は、9バイトの命令列になっていました。Java ではこれに当たる変換をがビルド時に済ませ、結果をというファイルに保存しています。V8 は同じ種類の変換を、実行時に中で行っています。

$ node --print-bytecode main.js から exports.greet の部分(アドレスは実行ごとに変わる)コマンド出力