EC-CUBE / EC-CUBE/ec-cube

eccube:plugin:enable 後、プラグインの TemplateEvent / FormExtension が反映されない(コンテナ再コンパイルが enabled 更新より先に走る)

Open
#7,018 1 comment 0 reactions 0 assignees View on GitHub
bug bug:Low
Dominant language
PHP
Stars
788
Forks
719
Avg merge
4d 4h
Merged PRs (30d)
39

Description

## 概要

コンテナキャッシュがプラグインディレクトリ配置前の状態で残っていると、`bin/console eccube:plugin:enable` が正常終了した後も、**そのプラグインの TemplateEvent / FormExtension / Twig 名前空間 / ルーティングがコンテナに反映されない**ことがあります。`dtb_plugin.enabled` は 1 になっているにもかかわらず、画面上はプラグインが無効のときと同じ表示になります。

`eccube:plugin:enable` は内部で `bin/console cache:clear --no-warmup` を実行しているため、利用者からは「有効化したのにキャッシュも消えているはずなのに反映されない」という状態に見えます。

有効化後に `bin/console cache:clear` を **2 回** 実行すると確実に解消します。1 回では解消しないことがあります(後述の「観測結果」を参照)。

## 発生条件

次の 2 つが揃ったときに発生します。

1. `app/Plugin/` が配置される **前** にコンパイルされたコンテナキャッシュ (`var/cache/`) が残っている
(`eccube:composer:require` や `eccube:plugin:install` はプラグインを配置しますが、コンテナキャッシュは再生成しません)
2. その状態で、他のコンソールコマンドを挟まずに `eccube:plugin:enable` を実行する

逆に、有効化の**前**に一度でもカーネルを起動するコマンド(`bin/console list` でも可)を実行しておくと発生しません。後述の「検証 3」を参照してください。

## 再現手順

EC-CUBE 4.4 に、コアエンティティ拡張とテンプレートフック(`TemplateEvent`)を持つプラグインを導入して確認しました。ここでは RelatedProduct44 を使っています。

```bash
# 本体インストール直後(=プラグイン配置前のキャッシュが残っている状態)から
bin/console eccube:plugin:install --code=RelatedProduct44 --path=/tmp/RelatedProduct44.tar.gz
bin/console eccube:plugin:enable --code=RelatedProduct44
# => [OK] Plugin Enabled.
```

この後に管理画面の商品編集画面 (`/admin/product/product/2/edit`) を開くと、プラグインが差し込むはずの関連商品フォームが描画されません。

`dtb_plugin.enabled = 1` が commit された後の、コンパイル済みコンテナの中身は次のとおりです。

```
コンパイル済みコンテナ : ContainerYz1xdvn
eccube.plugins.enabled : [] ← 空
@RelatedProduct44 の Twig パス : なし
admin_related_product_search ルート : なし
商品編集画面の関連商品フォーム : 描画されない
```

`bin/console cache:clear` を実行すると解消します。

```
コンパイル済みコンテナ : ContainerOM0aY8G
eccube.plugins.enabled : ['RelatedProduct44']
@RelatedProduct44 の Twig パス : あり
admin_related_product_search ルート : あり
商品編集画面の関連商品フォーム : 描画される
```

## 観測結果(`cache:clear` の回数と再現性)

Docker (`ghcr.io/ec-cube/ec-cube-php:8.2-apache-4.4` / SQLite / `APP_ENV=dev` `APP_DEBUG=1`) で、コンテナとボリュームを毎回破棄して本体インストールからやり直し、entrypoint を

```
eccube:plugin:install --if-not-exists && eccube:plugin:enable && (cache:clear をN回) && apache2-foreground
```

として N を変えたときの結果です。

| entrypoint の `cache:clear` | 試行回数 | 結果 |
|---|---|---|
| 0 回 | 1 | 正常(フックが反映される) |
| 1 回 | 2 | **1 回成功 / 1 回失敗** |
| 2 回 | 2 | 正常 |

**1 回のときだけ間欠的に失敗します。** 失敗したケースでは、`cache:clear` が完了した後のコンパイル済みコンテナが `eccube.plugins.enabled => []` のままでした。その状態からさらに `cache:clear` をもう 1 回実行すると `['RelatedProduct44']` になり、画面も正常になります。

| 段階(1 回版が失敗したビルド) | active container | `eccube.plugins.enabled` | 商品編集画面 |
|---|---|---|---|
| entrypoint 完了時(`cache:clear` 1 回済み) | `ContainerYz1xdvn` | `[]` | 反映されない |
| + `bin/console cache:clear` | `ContainerOM0aY8G` | `['RelatedProduct44']` | 反映される |

0 回のケースで正常になるのは、`eccube:plugin:enable` 内部の `cache:clear --no-warmup` がキャッシュディレクトリを空のまま残し、その後の最初の HTTP リクエストが `enabled = 1` を読んで正しくコンパイルするためと考えられます。

## 原因

`eccube:plugin:enable` **コマンド自身のカーネル起動時に行われるコンテナ再コンパイルが、`enabled` フラグを更新する前に走る**ことが原因です。

1. 発生条件 1 の状態では、キャッシュ済みコンテナは `app/Plugin/` が存在しない時点のものです。プラグインディレクトリが増えたことで `Kernel::configureContainer()` の glob リソース等が変化しているため、`APP_DEBUG=1` の環境では**次にカーネルが起動した時点でコンテナが再コンパイルされます**。

2. `eccube:plugin:enable` の場合、その「次のカーネル起動」はコマンド自身の起動です。この時点では `PluginService::enable()` はまだ実行されておらず、`dtb_plugin.enabled` は 0 のままです。

3. `EccubeExtension::configurePlugins()` は**コンテナのコンパイル時**に `dtb_plugin` を直接 SELECT して `eccube.plugins.enabled` を決めるため、ここで `eccube.plugins.enabled => []` のコンテナがダンプされます。

https://github.com/EC-CUBE/ec-cube/blob/4.4/src/Eccube/DependencyInjection/EccubeExtension.php#L133-L204

このパラメータを使って Twig パス (`configureTwigPaths()`) ・翻訳 (`configureTranslations()`) ・ルーティング (`Kernel::configureRoutes()`) が登録されるため、これらがすべて欠落します。

4. その後 `PluginService::enable()` が `enabled = 1` を commit し、`PluginEnableCommand` が `PluginCommandTrait::clearCache()` を呼びます。

https://github.com/EC-CUBE/ec-cube/blob/4.4/src/Eccube/Command/PluginEnableCommand.php#L55-L60
https://github.com/EC-CUBE/ec-cube/blob/4.4/src/Eccube/Command/PluginCommandTrait.php#L40-L52

つまり **「コンテナの再コンパイルが起きるタイミング」と「`enabled` フラグが更新されるタイミング」が逆順**になっているのが原因です。

### 検証 3: 有効化の前にカーネルを起動しておくと発生しない

上記が原因であることは、有効化の前に一度カーネルを起動させて「プラグイン配置後・無効のまま」の再コンパイルを済ませておくと発生しなくなることで確認できます。

```bash
# (発生条件 1 の状態を作ってから)
bin/console list > /dev/null # ← ここで再コンパイルが起きる (enabled=0 のまま)
bin/console eccube:plugin:enable --code=RelatedProduct44
```

この場合、`eccube:plugin:enable` の起動時には再コンパイルが不要なため手順 3 が起きず、内部の `cache:clear --no-warmup` がキャッシュを空にしたまま終わります。次のリクエストで `enabled = 1` を読んだ正しいコンテナがコンパイルされ、**追加の `cache:clear` なしで正常に動作します**。

### 未解明の点

「有効化後の `cache:clear` 1 回目でも `eccube.plugins.enabled` が空のままになることがある」という挙動は、上記の説明だけでは説明しきれていません。

- `cache:clear` を単独で実行した場合は、キャッシュディレクトリが空になる(コンパイル済みコンテナが残らない)ことを確認しています。
- 一方、`eccube:plugin:enable` の直後に実行した場合は、`eccube.plugins.enabled => []` のコンテナが残ることがあります。
- `cache:clear` が warmup のために同一プロセス内でカーネルを再起動する際、すでにロード済みのコンテナクラスが再利用されている可能性を疑っていますが、**未確定**です。

間欠的であることから、なんらかのタイミング依存があると思われます。

## 影響

- プラグインを導入する CI / Docker / プロビジョニングのスクリプトで、`eccube:plugin:enable` の後に `cache:clear` を明示的に足していないと、プラグインが「有効なのに何も起きない」状態になります。
- `[OK] Plugin Enabled.` と表示され `dtb_plugin.enabled` も 1 のため、原因が分かりにくいです。
- 間欠的に発生するため、CI で不安定な失敗として現れることがあります。

## 回避策

`eccube:plugin:enable` の後に、別プロセスで `bin/console cache:clear` を **2 回** 実行する。

```bash
bin/console eccube:plugin:enable --code=
bin/console cache:clear
bin/console cache:clear
```

## 修正案(参考)

有効化によって `dtb_plugin` が変化したことをコンテナの新鮮さ判定に反映できれば根本解決になると思われます。たとえば

- `EccubeExtension::configurePlugins()` で読んだ `dtb_plugin` の内容をコンテナのリソース(`ContainerBuilder::addResource()`)として登録する
- あるいは `PluginEnableCommand` が `cache:clear` の前にキャッシュディレクトリを確実に無効化する

といった方向が考えられます。

## 検証環境

- EC-CUBE 4.4(Docker イメージ `ghcr.io/ec-cube/ec-cube-php:8.2-apache-4.4`)
- PHP 8.2.31 / Symfony 7.4 / SQLite / `APP_ENV=dev` `APP_DEBUG=1`
- 検証に使用したプラグイン: RelatedProduct44([EC-CUBE/related-product-plugin#91](https://github.com/EC-CUBE/related-product-plugin/pull/91) のブランチ)

`APP_ENV=test` など `APP_DEBUG=0` の環境については未検証です。

## 関連

- #6984 複数プラグインをまとめてインストールした後の有効化が MappingException で失敗する
「プラグイン配置前のコンテナキャッシュが残っている」という発生条件は共通ですが、あちらは有効化そのものが例外で失敗するのに対し、本件は**有効化は成功するが反映されない**という違いがあります。

Contributor guide

Open the contributing guide

Research direction

Reproduce the plugin installation and enablement sequence with the RelatedProduct44 setup, then inspect src/Eccube/DependencyInjection/EccubeExtension.php:133-204, PluginEnableCommand.php:55-60, and PluginCommandTrait.php:40-52. Trace when the container is compiled relative to the enabled flag update and cache clearing. Done means enabling a newly installed plugin consistently registers its TemplateEvent, FormExtension, Twig namespace, and routes without requiring a second manual cache clear.

Written by the indexing model from the issue text.

Assessment

Tech stack
php, symfony
Domain
backend
Issue type
Bug
Difficulty
5/5
Estimated time
Over a week
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
45/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.