はじめに
前回の記事では、Kong Gateway における言語別カスタムプラグインの性能比較を行いました。
その検証環境の構築で Lua 以外のカスタムプラグインの環境変数の設定で少々手こずったので内部で何をしているのか調査をしました。
Kong Gateway とは
Kong Gateway とは OSS のクラウドネイティブの API Gateway です。
本記事では深く説明しませんが、 @m5takeda さんの記事で詳しく解説されています。
カスタムプラグイン設定項目
Kong Gateway の公式ドキュメントを確認するとカスタムプラグインを利用する場合は以下の項目の設定が必要になります。
これらの設定が内部でどのように使用されているかを確認します。
plugins
pluginserver_names
pluginserver_XXX_socket
pluginserver_XXX_start_cmd
pluginserver_XXX_query_cmd
※Lua は plugins のみ
Kong 起動ログを確認
まず Kong Gateway の起動ログを確認してどのようなログが出力されているか確認してみます。
ログを見ると、以下のようなカスタムプラグイン関連のログを確認することができます。
内容としては、カスタムプラグインの読み込みとプラグインサーバーの起動ログになります。
2026-01-13 23:29:34.141 | 2026/01/13 14:29:33 [notice] 1#0: [kong] process.lua:98 [pluginserver] loading external plugins info
2026-01-13 23:29:34.614 | 2026/01/13 14:29:33 [notice] 1#0: [kong] process.lua:109 [pluginserver] loaded #3 external plugins info
2026-01-13 23:29:34.614 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol MsgPack:1 for plugin js-plugin
2026-01-13 23:29:34.615 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol ProtoBuf:1 for plugin go-plugin
2026-01-13 23:29:34.620 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol MsgPack:1 for plugin py-plugin
...
2026-01-13 23:29:36.575 | 2026/01/13 14:29:36 [notice] 2708#0: *3883 [kong] process.lua:160 [pluginserver] starting pluginserver process for go-plugin, context: ngx.timer
2026-01-13 23:29:36.578 | 2026/01/13 14:29:36 [notice] 2708#0: *3883 [kong] process.lua:169 [pluginserver] started, pid 2720, context: ngx.timer
2026-01-13 23:29:36.580 | 2026/01/13 14:29:36 [notice] 2708#0: *4407 [kong] process.lua:160 [pluginserver] starting pluginserver process for py-plugin, context: ngx.timer
2026-01-13 23:29:36.665 | 2026/01/13 14:29:36 [notice] 2708#0: *4407 [kong] process.lua:169 [pluginserver] started, pid 2726, context: ngx.timer
2026-01-13 23:29:36.665 | 2026/01/13 14:29:36 [notice] 2708#0: *5202 [kong] process.lua:160 [pluginserver] starting pluginserver process for js-plugin, context: ngx.timer
2026-01-13 23:29:36.667 | 2026/01/13 14:29:36 [notice] 2708#0: *5202 [kong] process.lua:169 [pluginserver] started, pid 2727, context: ngx.timer
Kong 起動ログ全量
2026-01-13 23:29:33.900 | 2026/01/13 14:29:33 [notice] 1#0: [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found
2026-01-13 23:29:34.141 | 2026/01/13 14:29:33 [notice] 1#0: [kong] process.lua:98 [pluginserver] loading external plugins info
2026-01-13 23:29:34.614 | 2026/01/13 14:29:33 [notice] 1#0: [kong] process.lua:109 [pluginserver] loaded #3 external plugins info
2026-01-13 23:29:34.614 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol MsgPack:1 for plugin js-plugin
2026-01-13 23:29:34.615 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol ProtoBuf:1 for plugin go-plugin
2026-01-13 23:29:34.620 | 2026/01/13 14:29:33 [notice] 1#0: [kong] init.lua:19 [pluginserver] loading protocol MsgPack:1 for plugin py-plugin
2026-01-13 23:29:34.863 | 2026/01/13 14:29:33 [notice] 1#0: [lua] init.lua:968: init(): [request-debug] token for request debugging: da53a957-d519-40b1-937c-d785353c1b0b
2026-01-13 23:29:34.907 | 2026/01/13 14:29:33 [notice] 1#0: using the "epoll" event method
2026-01-13 23:29:34.907 | 2026/01/13 14:29:33 [notice] 1#0: openresty/1.27.1.2
2026-01-13 23:29:34.907 | 2026/01/13 14:29:33 [notice] 1#0: OS: Linux 6.6.87.2-microsoft-standard-WSL2
2026-01-13 23:29:34.907 | 2026/01/13 14:29:33 [notice] 1#0: getrlimit(RLIMIT_NOFILE): 1048576:1048576
2026-01-13 23:29:34.907 | 2026/01/13 14:29:33 [notice] 1#0: start worker processes
2026-01-13 23:29:34.909 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2708
2026-01-13 23:29:34.910 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2709
2026-01-13 23:29:34.912 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2710
2026-01-13 23:29:34.913 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2711
2026-01-13 23:29:34.915 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2712
2026-01-13 23:29:34.916 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2713
2026-01-13 23:29:34.917 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2714
2026-01-13 23:29:34.919 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2715
2026-01-13 23:29:34.920 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2716
2026-01-13 23:29:34.923 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2717
2026-01-13 23:29:34.929 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2718
2026-01-13 23:29:34.932 | 2026/01/13 14:29:33 [notice] 1#0: start worker process 2719
2026-01-13 23:29:35.076 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [lua] broker.lua:215: init(): event broker is ready to accept connections on worker #0, context: init_worker_by_lua*
2026-01-13 23:29:35.173 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.174 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.179 | 2026/01/13 14:29:35 [notice] 2711#0: *4 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.180 | 2026/01/13 14:29:35 [notice] 2709#0: *2 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.186 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.251 | 2026/01/13 14:29:35 [notice] 2715#0: *8 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.267 | 2026/01/13 14:29:35 [notice] 2718#0: *10 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.272 | 2026/01/13 14:29:35 [notice] 2714#0: *7 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.272 | 2026/01/13 14:29:35 [notice] 2713#0: *6 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.372 | 2026/01/13 14:29:35 [notice] 2719#0: *12 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.372 | 2026/01/13 14:29:35 [notice] 2717#0: *11 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.372 | 2026/01/13 14:29:35 [notice] 2712#0: *5 [lua] license_helpers.lua:208: read_license_info(): [license-helpers] could not decode license JSON: No license found, context: init_worker_by_lua*
2026-01-13 23:29:35.468 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [lua] globalpatches.lua:84: sleep(): executing a blocking 'sleep' (0.001 seconds), context: init_worker_by_lua*
2026-01-13 23:29:35.472 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [lua] warmup.lua:120: single_dao(): Preloading 'services' into the core_cache..., context: init_worker_by_lua*
2026-01-13 23:29:35.472 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [lua] globalpatches.lua:84: sleep(): executing a blocking 'sleep' (0.002 seconds), context: init_worker_by_lua*
2026-01-13 23:29:35.475 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [lua] globalpatches.lua:84: sleep(): executing a blocking 'sleep' (0.001 seconds), context: init_worker_by_lua*
2026-01-13 23:29:35.476 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [lua] globalpatches.lua:84: sleep(): executing a blocking 'sleep' (0.002 seconds), context: init_worker_by_lua*
2026-01-13 23:29:35.482 | 2026/01/13 14:29:35 [notice] 2709#0: *2 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.483 | 2026/01/13 14:29:35 [notice] 2711#0: *4 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.484 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.569 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.576 | 2026/01/13 14:29:35 [notice] 2711#0: *4 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.576 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [lua] warmup.lua:169: single_dao(): finished preloading 'services' into the core_cache (in 0ms), context: init_worker_by_lua*
2026-01-13 23:29:35.577 | 2026/01/13 14:29:35 [notice] 2709#0: *2 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.577 | 2026/01/13 14:29:35 [notice] 2709#0: *2 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.579 | 2026/01/13 14:29:35 [notice] 2711#0: *4 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.579 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.579 | 2026/01/13 14:29:35 [notice] 2716#0: *9 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.666 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.667 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.673 | 2026/01/13 14:29:35 [notice] 2714#0: *7 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.767 | 2026/01/13 14:29:35 [notice] 2718#0: *10 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.768 | 2026/01/13 14:29:35 [notice] 2709#0: *2 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 98 ms, context: init_worker_by_lua*
2026-01-13 23:29:35.768 | 2026/01/13 14:29:35 [notice] 2710#0: *3 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 89 ms, context: init_worker_by_lua*
2026-01-13 23:29:35.770 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.773 | 2026/01/13 14:29:35 [notice] 2715#0: *8 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.774 | 2026/01/13 14:29:35 [notice] 2714#0: *7 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.777 | 2026/01/13 14:29:35 [notice] 2714#0: *7 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.782 | 2026/01/13 14:29:35 [notice] 2713#0: *6 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.784 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.785 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.863 | 2026/01/13 14:29:35 [notice] 2712#0: *5 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.864 | 2026/01/13 14:29:35 [notice] 2718#0: *10 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.864 | 2026/01/13 14:29:35 [notice] 2718#0: *10 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.866 | 2026/01/13 14:29:35 [notice] 2719#0: *12 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:35.869 | 2026/01/13 14:29:35 [notice] 2715#0: *8 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.870 | 2026/01/13 14:29:35 [notice] 2715#0: *8 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.874 | 2026/01/13 14:29:35 [notice] 2708#0: *1 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 82 ms, context: init_worker_by_lua*
2026-01-13 23:29:35.882 | 2026/01/13 14:29:35 [notice] 2712#0: *5 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.882 | 2026/01/13 14:29:35 [notice] 2712#0: *5 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.882 | 2026/01/13 14:29:35 [notice] 2713#0: *6 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.882 | 2026/01/13 14:29:35 [notice] 2713#0: *6 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.882 | 2026/01/13 14:29:35 [notice] 2719#0: *12 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:35.887 | 2026/01/13 14:29:35 [notice] 2719#0: *12 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:35.971 | 2026/01/13 14:29:35 [notice] 2718#0: *10 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 98 ms, context: init_worker_by_lua*
2026-01-13 23:29:35.976 | 2026/01/13 14:29:35 [notice] 2715#0: *8 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 86 ms, context: init_worker_by_lua*
2026-01-13 23:29:35.976 | 2026/01/13 14:29:35 [notice] 2712#0: *5 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 89 ms, context: init_worker_by_lua*
2026-01-13 23:29:36.064 | 2026/01/13 14:29:35 [notice] 2717#0: *11 [kong] events.lua:503 [ace] building initial operations router, context: init_worker_by_lua*
2026-01-13 23:29:36.179 | 2026/01/13 14:29:35 [notice] 2717#0: *11 [kong] events.lua:510 [ace] registering operations router events., context: init_worker_by_lua*
2026-01-13 23:29:36.179 | 2026/01/13 14:29:35 [notice] 2717#0: *11 [kong] events.lua:595 [ace] creating operations router rebuild timer., context: init_worker_by_lua*
2026-01-13 23:29:36.375 | 2026/01/13 14:29:36 [notice] 2717#0: *11 [kong] plugins_iterator.lua:667 executing plugin 'degraphql:configure took excessively long: 103 ms, context: init_worker_by_lua*
2026-01-13 23:29:36.575 | 2026/01/13 14:29:36 [notice] 2708#0: *3883 [kong] process.lua:160 [pluginserver] starting pluginserver process for go-plugin, context: ngx.timer
2026-01-13 23:29:36.578 | 2026/01/13 14:29:36 [notice] 2708#0: *3883 [kong] process.lua:169 [pluginserver] started, pid 2720, context: ngx.timer
2026-01-13 23:29:36.580 | 2026/01/13 14:29:36 [notice] 2708#0: *4407 [kong] process.lua:160 [pluginserver] starting pluginserver process for py-plugin, context: ngx.timer
2026-01-13 23:29:36.665 | 2026/01/13 14:29:36 [notice] 2708#0: *4407 [kong] process.lua:169 [pluginserver] started, pid 2726, context: ngx.timer
2026-01-13 23:29:36.665 | 2026/01/13 14:29:36 [notice] 2708#0: *5202 [kong] process.lua:160 [pluginserver] starting pluginserver process for js-plugin, context: ngx.timer
2026-01-13 23:29:36.667 | 2026/01/13 14:29:36 [notice] 2708#0: *5202 [kong] process.lua:169 [pluginserver] started, pid 2727, context: ngx.timer
2026-01-13 23:29:36.669 | 2026/01/13 14:29:36 [notice] 2716#0: *14 [lua] worker.lua:304: communicate(): worker #8 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.669 | 2026/01/13 14:29:36 [notice] 2711#0: *292 [lua] worker.lua:304: communicate(): worker #3 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.671 | 2026/01/13 14:29:36 [notice] 2709#0: *1314 [lua] worker.lua:304: communicate(): worker #1 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.671 | 2026/01/13 14:29:36 [notice] 2714#0: *1183 [lua] worker.lua:304: communicate(): worker #6 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.671 | 2026/01/13 14:29:36 [notice] 2710#0: *1180 [lua] worker.lua:304: communicate(): worker #2 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.671 | 2026/01/13 14:29:36 [notice] 2715#0: *2628 [lua] worker.lua:304: communicate(): worker #7 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.672 | 2026/01/13 14:29:36 [notice] 2712#0: *4529 [lua] worker.lua:304: communicate(): worker #4 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.672 | 2026/01/13 14:29:36 [notice] 2719#0: *4535 [lua] worker.lua:304: communicate(): worker #11 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.672 | 2026/01/13 14:29:36 [notice] 2708#0: *1326 [lua] broker.lua:263: run(): worker #8 connected to events broker (worker pid: 2716), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.672 | 2026/01/13 14:29:36 [notice] 2708#0: *1327 [lua] broker.lua:263: run(): worker #3 connected to events broker (worker pid: 2711), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.672 | 2026/01/13 14:29:36 [notice] 2708#0: *1330 [lua] broker.lua:263: run(): worker #1 connected to events broker (worker pid: 2709), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.673 | 2026/01/13 14:29:36 [notice] 2713#0: *4130 [lua] worker.lua:304: communicate(): worker #5 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.673 | 2026/01/13 14:29:36 [notice] 2708#0: *1329 [lua] broker.lua:263: run(): worker #6 connected to events broker (worker pid: 2714), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.673 | 2026/01/13 14:29:36 [notice] 2708#0: *1332 [lua] worker.lua:304: communicate(): worker #0 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.674 | 2026/01/13 14:29:36 [notice] 2708#0: *5859 [lua] broker.lua:263: run(): worker #7 connected to events broker (worker pid: 2715), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.674 | 2026/01/13 14:29:36 [notice] 2708#0: *1328 [lua] broker.lua:263: run(): worker #2 connected to events broker (worker pid: 2710), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.674 | 2026/01/13 14:29:36 [notice] 2708#0: *5864 [lua] broker.lua:263: run(): worker #4 connected to events broker (worker pid: 2712), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.674 | 2026/01/13 14:29:36 [notice] 2708#0: *5866 [lua] broker.lua:263: run(): worker #11 connected to events broker (worker pid: 2719), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.674 | 2026/01/13 14:29:36 [notice] 2708#0: *5862 [lua] broker.lua:263: run(): worker #5 connected to events broker (worker pid: 2713), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.675 | 2026/01/13 14:29:36 [notice] 2708#0: *5855 [lua] broker.lua:263: run(): worker #0 connected to events broker (worker pid: 2708), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.686 | 2026/01/13 14:29:36 [notice] 2718#0: *6457 [lua] worker.lua:304: communicate(): worker #10 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:36.686 | 2026/01/13 14:29:36 [notice] 2708#0: *6462 [lua] broker.lua:263: run(): worker #10 connected to events broker (worker pid: 2718), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.774 | 2026/01/13 14:29:36 [notice] 2708#0: *7103 [lua] broker.lua:263: run(): worker #9 connected to events broker (worker pid: 2717), client: unix:, server: kong_worker_events, request: "GET / HTTP/1.1", host: "localhost"
2026-01-13 23:29:36.774 | 2026/01/13 14:29:36 [notice] 2717#0: *7101 [lua] worker.lua:304: communicate(): worker #9 is ready to accept events from unix:/usr/local/kong/sockets/we, context: ngx.timer
2026-01-13 23:29:40.257 | 2026/01/13 14:29:40 [notice] 2716#0: *25 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.258 | 2026/01/13 14:29:40 [notice] 2716#0: *23 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.375 | 2026/01/13 14:29:40 [notice] 2711#0: *299 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.379 | 2026/01/13 14:29:40 [notice] 2711#0: *301 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.466 | 2026/01/13 14:29:40 [notice] 2710#0: *1321 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.466 | 2026/01/13 14:29:40 [notice] 2710#0: *1384 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.486 | 2026/01/13 14:29:40 [notice] 2709#0: *2623 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.488 | 2026/01/13 14:29:40 [notice] 2708#0: *2567 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.489 | 2026/01/13 14:29:40 [notice] 2709#0: *2625 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.550 | 2026/01/13 14:29:40 [notice] 2708#0: *2608 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.550 | 2026/01/13 14:29:40 [notice] 2714#0: *1323 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.551 | 2026/01/13 14:29:40 [notice] 2714#0: *1325 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.582 | 2026/01/13 14:29:40 [notice] 2715#0: *3885 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.584 | 2026/01/13 14:29:40 [notice] 2715#0: *3887 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.595 | 2026/01/13 14:29:40 [notice] 2719#0: *4598 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.650 | 2026/01/13 14:29:40 [notice] 2712#0: *4545 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.652 | 2026/01/13 14:29:40 [notice] 2719#0: *4664 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.652 | 2026/01/13 14:29:40 [notice] 2712#0: *4543 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.661 | 2026/01/13 14:29:40 [notice] 2713#0: *5045 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.662 | 2026/01/13 14:29:40 [notice] 2713#0: *5229 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.666 | 2026/01/13 14:29:40 [notice] 2718#0: *6465 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.668 | 2026/01/13 14:29:40 [notice] 2718#0: *6467 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.751 | 2026/01/13 14:29:40 [notice] 2717#0: *7109 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
2026-01-13 23:29:40.751 | 2026/01/13 14:29:40 [notice] 2717#0: *7111 [kong] setup.lua:134 finished warming up targets DNS entries and and initial identity tokens, context: ngx.timer
内部処理
実際にログを基に GitHub のソースコードから実際に内部でどのような処理が行われているか確認します。
カスタムプラグイン読み込み
最初にログの最初に出力されていたカスタムプラグイン読み込み処理を解析してみます。
ログメッセージから処理を探してみると、読み込みの処理は kong/runloop/plugin_servers/process.lua の load_external_plugins_info() で実装されていました。
-- kong/runloop/plugin_servers/process.lua
function _M.load_external_plugins_info(kong_conf)
local available_external_plugins = {}
kong.log.notice("[pluginserver] loading external plugins info")
for _, pluginserver in ipairs(kong_conf.pluginservers) do
local plugin_info, err = query_external_plugin_info(pluginserver)
if not plugin_info then
return nil, err
end
available_external_plugins[plugin_info.name] = plugin_info
end
kong.log.notice("[pluginserver] loaded #", #kong_conf.pluginservers, " external plugins info")
return available_external_plugins
end
コードを確認すると、設定の kong_conf.pluginservers の設定を取得してループで query_external_plugin_info() という関数を動かしているようです。
では query_external_plugin_info() では何をしているかを確認します。
query_external_plugin_info() の実装は以下になります(コメントは削除しています)。
-- kong/runloop/plugin_servers/process.lua
local function query_external_plugin_info(server_def)
if not server_def.query_command then
return nil, "no info query for " .. server_def.name
end
local fd, err = io.popen(server_def.query_command)
if not fd then
return nil, string.format("error loading plugins info from [%s]: %s", server_def.name, err)
end
local infos_dump = fd:read("*a")
fd:close()
local dump, err = cjson_decode(infos_dump)
if err then
return nil, "failed decoding plugin info: " .. err
end
if type(dump) ~= "table" then
return nil, string.format("not a plugin info table: \n%s\n%s", server_def.query_command, infos_dump)
end
server_def.protocol = dump.Protocol or "MsgPack:1"
local info = (dump.Plugins or dump)[1]
return {
server_def = server_def,
name = info.Name,
PRIORITY = info.Priority,
VERSION = info.Version,
schema = info.Schema,
phases = info.Phases,
}
end
行っている内容としては、query_command(Kong の設定で指定した pluginserver_XXX_query_cmd)を ip.popen でコマンド実行し、その結果を返却しています。
実際に Go で作成したプラグインのバイナリを実行してみると以下のような出力がされました。
$ ./go-plugin -dump | jq
{
"Protocol": "ProtoBuf:1",
"SocketPath": "/usr/local/kong/go-plugin.socket",
"Plugins": [
{
"Name": "go-plugin",
"Phases": ["access"],
"Version": "0.2",
"Priority": 1,
"Schema": {
"fields": [
{
"config": {
"type": "record",
"fields": [
{
"valkeyhost": {
"type": "string"
}
},
{
"valkeyport": {
"type": "integer"
}
}
]
}
}
],
"name": "go-plugin"
}
}
]
}
-dump オプションを利用しているので作成したカスタムプラグインのスキーマが返されていますね。
この結果を取得することができたらログに [pluginserver] loaded #3 external plugins info が出力されています。
カスタムプラグインサーバー起動
では次にカスタムプラグインサーバーを起動している処理を確認します。
この処理も同じく kong/runloop/plugin_servers/process.lua 内で実装されています。
該当箇所は以下の 2 つです。
-- kong/runloop/plugin_servers/process.lua
local function pluginserver_timer(premature, server_def)
if premature then
return
end
if ngx.config.subsystem ~= "http" then
return
end
local next_spawn = 0
while not ngx.worker.exiting() do
if ngx.now() < next_spawn then
ngx.sleep(next_spawn - ngx.now())
end
kong.log.notice("[pluginserver] starting pluginserver process for ", server_def.name or "")
local proc = assert(ngx_pipe.spawn("exec " .. server_def.start_command, {
merge_stderr = true,
}))
server_rt[server_def.name] = {
proc = proc,
}
next_spawn = ngx.now() + 1
proc:set_timeouts(nil, nil, nil, 0)
kong.log.notice("[pluginserver] started, pid ", proc:pid())
while true do
grab_logs(proc, server_def.name)
local ok, reason, status = proc:wait()
if ok == false and reason == "exit" and status == 127 then
kong.log.err(string.format(
"[pluginserver] external pluginserver %q start command %q exited with \"command not found\"",
server_def.name, server_def.start_command))
break
elseif ok ~= nil or reason == "exited" or ngx.worker.exiting() then
kong.log.notice("external pluginserver '", server_def.name, "' terminated: ", tostring(reason), " ", tostring(status))
break
end
end
end
kong.log.notice("[pluginserver] exiting: pluginserver '", server_def.name, "' not respawned.")
end
-- kong/runloop/plugin_servers/process.lua
function _M.start_pluginservers()
local kong_config = kong.configuration
if worker_id() == 0 then
local pluginserver_timer = pluginserver_timer
for _, server_def in ipairs(kong_config.pluginservers) do
if server_def.start_command then
native_timer_at(0, pluginserver_timer, server_def)
end
end
end
return true
end
実際の処理を pluginserver_timer() で実装して、start_pluginservers() で呼び出している形です。
それでは処理を詳しく見ていきます。
最初に start_pluginservers() を確認します。
まず start_pluginservers() では、カスタムプラグイン周りの設定を取得して、その中に pluginserver_XXX_start_cmd が指定されている場合に pluginserver_timer() に値を渡して実行しています。
重要な処理は以下です。
local function pluginserver_timer(premature, server_def)
...
while not ngx.worker.exiting() do
...
kong.log.notice("[pluginserver] starting pluginserver process for ", server_def.name or "")
local proc = assert(ngx_pipe.spawn("exec " .. server_def.start_command, {
merge_stderr = true,
}))
server_rt[server_def.name] = {
proc = proc,
}
next_spawn = ngx.now() + 1
proc:set_timeouts(nil, nil, nil, 0)
kong.log.notice("[pluginserver] started, pid ", proc:pid())
...
end
...
end
実際にカスタムプラグインサーバーの起動コマンドを実行している部分は以下になります。
local proc = assert(ngx_pipe.spawn("exec " .. server_def.start_command, {
merge_stderr = true,
}))
この処理では外部プロセスでカスタムプラグインサーバーの起動コマンドを実行しています。
起動コマンドが実行できたらログに起動したプラグインサーバーの pid が出力されます。
pluginserver_XXX_socket
最後に、pluginserver_XXX_socket について確認します。
この設定値は、各プラグインサーバー（Go / Python / JavaScript）が待ち受ける UNIX ソケットのパスを指定するものです。
デフォルトのログレベルでは、この設定に関するログは出力されません。
確認するには、ログレベルを debug にする必要があります。
起動ログ例（抜粋）
2026/01/13 14:49:34 [info] 2708#0: *7096 [go-plugin:2720] 2026/01/13 14:49:34 Listening on socket: /usr/local/kong/go-plugin.socket, context: ngx.timer
2026/01/13 14:49:34 [info] 2708#0: *7097 [py-plugin:2721] INFO - [22:49:34] server started at path /usr/local/kong/py-plugin.sock, context: ngx.timer
2026/01/13 14:49:34 [info] 2708#0: *7098 [js-plugin:2728] 2026-01-13T14:49:34.701Z [INFO] server started at /usr/local/kong/js-pluginserver.sock, context: ngx.timer
ログの形式がそれぞれ異なるのは、
pluginserver_XXX_start_cmd に設定した「カスタムプラグインサーバー起動コマンド」の標準出力が、そのまま Kong のログに出力されているためです（カスタムプラグインサーバー起動）。
Go / Python / JavaScript プラグインは Kong 本体とは別プロセスとして起動しているため、Kongとプラグインサーバーの通信のため pluginserver_XXX_socket を設定する必要があります。
まとめ
今回は、Kong Gateway で Lua 以外のカスタムプラグイン（Go / Python / JavaScript）を利用する際に必要となる各種設定項目について、
起動ログとソースコードを手掛かりに、内部でどのような処理が行われているのかを確認しました。
調査の結果、以下の点が分かりました。
-
pluginserver_XXX_query_cmdは、Kong 起動時に実行されプラグインのメタ情報を取得するために使用されている -
pluginserver_XXX_start_cmdは、Kong の起動後に外部プロセスとしてプラグインサーバーを起動するためのコマンドである -
pluginserver_XXX_socketは、Kong 本体と別プロセスで動作するプラグインサーバーとの間を接続するための内部通信（IPC）用の UNIX ソケットとして利用されている
今回実際に起動ログや process.lua の処理を追っていくことで、カスタムプラグインの設定値の意味を明確にすることができました。
これまではカスタムプラグインは Lua だけしか使っていませんでしたが、今回の調査を機にそれ以外の言語でもカスタムプラグインを作成してみようと思います。