Minecraft Forgeを使うとログが破滅する件

ForgeでMod開発をしている時、よくMinecraft game outputとにらめっこをします。
ある時ふとバニラの出力と見比べたら出力がおかしかったので、
その修正方法をここに残しておきます。

## 調査環境
- Windows 11
- Minecraft Launcher 2.2.8545 (ストア版ではない方)
- Minecraft Forge 1.12.2-14.23.5.2860

## Minecraft game outputの比較
### 正常な表示(バニラ)
Levels(上のほう)が正しく振り分けられおり、またログが出力された時間やスレッドも
分かりやすい位置に表示されています。
![vanilla.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/208716/f71a1751-5bfe-d059-484d-2dd3a9ae8eb6.png)

### おかしな表示(Forge)
Levelsが全てinfoになっています。
(debugはランチャーのもの、warnはログが正しく出力できない旨のエラー)
また、出力された時間やスレッドなどが全てログ本文のあった位置に出力されており、
非常に読みづらいです。
![forge.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/208716/4fa7edca-08ff-387c-65fa-57b60063e357.png)

## 何故こうなるのか
ここからはLog4jの設定の話になります。

### バニラの設定ファイル
バニラのlog4j2.xml(に該当するファイル)では、次のように定義されています。

```xml:client-1.12.xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
    <Appenders>
        <Console name="SysOut" target="SYSTEM_OUT">
            <LegacyXMLLayout />
        </Console>
        <!-- 関係がないので省略 -->
    </Appenders>
    <Loggers>
        <Root level="info">
            <!-- 関係がないので省略 -->
            <AppenderRef ref="SysOut"/>
        </Root>
    </Loggers>
</Configuration>
```

Appenderは、[こちらの記事](https://qiita.com/12345/items/192ff718c3942b85daed)によると

https://qiita.com/12345/items/192ff718c3942b85daed

> Appenderはログの出力先（出力方法）・出力レイアウトなどを定義する。

とのことです。バニラの設定では、LegacyXMLLayoutを使用する設定になっています。

### Forgeの設定ファイル
Forgeのlog4j2.xmlでは、次のように定義されています。

```xml:log4j2.xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" packages="net.minecraftforge.server.terminalconsole.util">
    <Appenders>
        <Console name="SysOut" target="SYSTEM_OUT">
            <PatternLayout>
                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg{nolookups}%n">
                    <!-- don't include the full logger name for Mojang's logs since they use full class names and it's very verbose -->
                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss}] [%t/%level] [minecraft/%logger{1}]: %msg{nolookups}%n"/>
                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss}] [%t/%level] [mojang/%logger{1}]: %msg{nolookups}%n"/>
                </LoggerNamePatternSelector>
            </PatternLayout>
        </Console>
        <!-- 関係がないので省略 -->
    </Appenders>
    <Loggers>
        <!-- 関係がないので省略 -->
        <Root level="all">
            <AppenderRef ref="SysOut" level="${sys:forge.logging.console.level:-info}"/>
        </Root>
    </Loggers>
</Configuration>
```

こちらでは、バニラとは出力形式が変更されていることが分かります。
恐らく、この変更によってMinecraft game outputがログのパースに失敗しているものと
思われます。

## Log4jの設定を変更する
問題の原因はログの出力形式によるものでした。Log4jの設定を書き換えることで修正が
できそうです。
次の手順で修正を行います。

1. log4j2.xmlを書き換え、`%AppData%\.minecraft\assets\log_configs`に配置する
1. バージョンの定義ファイルである`%AppData%\.minecraft\versions\1.12.2-forge-14.23.5.2860\1.12.2-forge-14.23.5.2860.json`を書き換える

### 1. log4j2.xmlを書き換え所定のディレクトリに配置する
Jarファイルからlog4j2.xmlを取り出し、バニラのlog4j2.xml(に該当するファイル)と
同様の設定に書き換えます。

具体的には、Appenderにて`SysOut`の出力形式を`PatternLayout`から`LegacyXMLLayout`に
書き換え、Loggerで設定している`level`(出力されるログのレベル)の設定を削除します。
それ以外の設定はそのままにしておきます。

なお、この後の手順で面倒なことになるので、書き換えたファイルを用意しました。
[こちら](https://files.siro256.dev/static/fix_forge_log4j2.xml)からダウンロードできます。(こちらのURLは後から変更する可能性があります)

https://files.siro256.dev/static/fix_forge_log4j2.xml

<details>
<summary>書き換えたコードはこちら</summary>
<div>

```xml:fix_forge_log4j2.xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" packages="net.minecraftforge.server.terminalconsole.util">
    <Appenders>
        <Console name="SysOut" target="SYSTEM_OUT">
            <!--
            <PatternLayout>
                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg{nolookups}%n">
                    <!- don't include the full logger name for Mojang's logs since they use full class names and it's very verbose ->
                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss}] [%t/%level] [minecraft/%logger{1}]: %msg{nolookups}%n"/>
                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss}] [%t/%level] [mojang/%logger{1}]: %msg{nolookups}%n"/>
                </LoggerNamePatternSelector>
            </PatternLayout>
            -->
            <LegacyXMLLayout/>
        </Console>
        <Queue name="ServerGuiConsole" ignoreExceptions="true">
            <PatternLayout>
                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg{nolookups}%n">
                    <!-- don't include the full logger name for Mojang's logs since they use full class names and it's very verbose -->
                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss}] [%t/%level] [minecraft/%logger{1}]: %msg{nolookups}%n"/>
                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss}] [%t/%level] [mojang/%logger{1}]: %msg{nolookups}%n"/>
                </LoggerNamePatternSelector>
            </PatternLayout>
        </Queue>
        <RollingRandomAccessFile name="File" fileName="logs/latest.log" filePattern="logs/%d{yyyy-MM-dd}-%i.log.gz">
            <PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg{nolookups}%n"/>
            <Policies>
                <TimeBasedTriggeringPolicy/>
                <OnStartupTriggeringPolicy/>
            </Policies>
        </RollingRandomAccessFile>
        <RollingRandomAccessFile name="DebugFile" fileName="logs/debug.log" filePattern="logs/debug-%i.log.gz">
            <PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg{nolookups}%n"/>
            <Policies>
                <OnStartupTriggeringPolicy/>
                <SizeBasedTriggeringPolicy size="200MB"/>
            </Policies>
            <DefaultRolloverStrategy max="5" fileIndex="min"/>
        </RollingRandomAccessFile>
    </Appenders>
    <Loggers>
        <!-- make sure mojang's logging is set to 'info' so that their LOGGER.isDebugEnabled() behavior isn't active -->
        <Logger level="${sys:forge.logging.mojang.level:-info}" name="com.mojang"/>
        <Logger level="${sys:forge.logging.mojang.level:-info}" name="net.minecraft"/>
        <Root level="all">
            <filters>
                <MarkerFilter marker="NETWORK_PACKETS" onMatch="DENY" onMismatch="NEUTRAL"/>
            </filters>
            <!--<AppenderRef ref="SysOut" level="${sys:forge.logging.console.level:-info}"/>-->
            <AppenderRef ref="SysOut"/>
            <AppenderRef ref="ServerGuiConsole" level="${sys:forge.logging.console.level:-info}"/>
            <AppenderRef ref="File" level="${sys:forge.logging.file.level:-info}"/>
            <AppenderRef ref="DebugFile" level="${sys:forge.logging.debugFile.level:-trace}"/>
        </Root>
    </Loggers>
</Configuration>

```

</div>
</details>

このファイルを、`%AppData%\.minecraft\assets\log_configs`に配置します。

### 2. バージョンの定義ファイルを書き換える
現在のバージョン定義ファイルでは、Log4jの設定を上書きすることができる項目が
追加されています。2021年末のLog4Shellの問題が発覚するより前に見た覚えがないので、
この脆弱性を解決するために追加された項目なのかもしれません。
今回はこれを利用します。

`%AppData%\.minecraft\versions\`には様々なバージョンの定義ファイルが配置されて
いますが、今回はこの中の`.\1.12.2-forge-14.23.5.2860\1.12.2-forge-14.23.5.2860.json`を編集します。
試してはいませんが、他のバージョンも同じ方法で修正できると思われます。

このjsonの中に、次のような項目があるはずです。

```json:1.12.2-forge-14.23.5.2860.json&nbsp;(14行目付近)
{
    "inheritsFrom": "1.12.2",
    "logging": {

    },
    "minecraftArguments": "--username ${auth_player_name} ..."
}
```

この`logging`という項目が、Log4jの設定を上書きするための項目になっています。
ここを、以下のように書き換えます。

```json:1.12.2-forge-14.23.5.2860.json
{
    "logging": {
        "client": {
            "argument": "-Dlog4j.configurationFile=${path}",
            "file": {
                "id": "fix_forge_log4j2.xml",
                "sha1": "664b7bac74374187ca7e1a129ad989c6fa76382a",
                "size": 3444,
                "url": ""
            },
            "type": "log4j2-xml"
        }
    },
}
```

先ほど設定を書き換えたlog4j2.xmlのダウンロードURLを置きましたが、ここにSHA1と
サイズを記述する必要があるためです。
ご自身でファイルを書き換え配置した場合は、2つの値を適切なものに設定してください。

:::note warn
配置されているファイルと2つの値が異なる場合ファイルが削除されてしまうよう
なので注意が必要です。
:::

以上でLog4jの設定の変更は終了です。

### 変更後の出力
Levelsが正しく割り振られ、ログの出力もバニラのような読みやすい形式になっています。
![forge_fixed.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/208716/4071a972-b74d-b987-ac00-ab995689f329.png)