Log4J Asyncやったら遅くなるんだけど

みんな大好きLog4J。この記事は非同期の設定
作者はロギングのシステムについてはあんまりわかってない。
WEBでまよったりして動かなかったので記事まとめる。

# 結論
なんか私の環境ではAsyncじゃないほうが速い。

# 動機
WEBアプリケーションのボトルネックはロギングとDBなので速いものを求めた。

# 公式
http://logging.apache.org/log4j/2.x/manual/async.html
6-68倍速とのこと。すごい。
監査証跡ログとかExceptionログとかに使わないほうが良いよ！っていってるけどまぁ大丈夫だよね。使う。

# 要求
IPAの文書に従うと(プロジェクトメンバーが読んでくれてスペック教えてくれた)、
* SQLのログ
* アクセスログ
* アプリのログ(自由形式？)
を作っておけとのこと。
アクセスログはWEBサーバーで出しても良いんだろうけどアプリ側でも出すことにする
よって一旦3つのロガーを設定する例を考えた

# 書き方
## Asyncで囲むAsyncLoggerと書く
前者だと私が試した感じでうまく行かなかった。なんで？→AsyncLogger使う
## RollingRandomAccessFileAppenderとFileAppenderとRollingFileAppender
RandomAccessFileが速いらしいので採用

# log4j2.xml
実際わからんよね。むずい。

## の前にlog4j.properties
log4j.properties作って置かないとおこられるので雑に置く。多分FWのVert.xの要求だとおもうんだけど追いかけていない

```
log4j.rootLogger=ERROR, console
log4j.logger.xxx=ERROR, console
log4j.appender.console=org.apache.log4j.ConsoleAppender
log4j.appender.console.layout=org.apache.log4j.PatternLayout
log4j.appender.console.layout.ConversionPattern=%d [%-5p-%c] %m%n
```

## log4j.xml

愚直に書くよ

```xml
<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="WARN">
  <Appenders>
    <Console name="Console">
      <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
    </Console>
    <RollingRandomAccessFile name="AppLog" fileName="logs/app.log" filePattern="logs/old/app-%d{yyyy-MM-dd}.log.gz"
                 ignoreExceptions="false">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
      <TimeBasedTriggeringPolicy/>
    </RollingRandomAccessFile>
    <RollingRandomAccessFile name="AccessLog" fileName="logs/access.log" filePattern="logs/old/access-%d{yyyy-MM-dd}.log.gz"
                 ignoreExceptions="false">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
      <TimeBasedTriggeringPolicy/>
    </RollingRandomAccessFile>
    <RollingRandomAccessFile name="ErrorLog" fileName="logs/error.log" filePattern="logs/old/error-%d{yyyy-MM-dd}.log.gz"
                 ignoreExceptions="false">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
      <TimeBasedTriggeringPolicy/>
    </RollingRandomAccessFile>
    <RollingRandomAccessFile name="SQLLog" fileName="logs/sql.log" filePattern="logs/old/sql-%d{yyyy-MM-dd}.log.gz"
                 ignoreExceptions="false">
      <PatternLayout>
        <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
      </PatternLayout>
      <TimeBasedTriggeringPolicy/>
    </RollingRandomAccessFile>
    <Async name="AppAsync">
      <AppenderRef ref="Console"/>
    </Async>
  </Appenders>
  <Loggers>
    <Root level="info">
      <AppenderRef ref="AppAsync"/>
    </Root>
    <AsyncLogger level="debug" name="access-log">
      <AppenderRef ref="AccessLog"/>
    </AsyncLogger>
    <AsyncLogger level="debug" name="error-log">
      <AppenderRef ref="ErrorLog"/>
    </AsyncLogger>
    <AsyncLogger level="debug" name="sql-log">
      <AppenderRef ref="SQLLog"/>
    </AsyncLogger>
  </Loggers>
</Configuration>
```

# パフォーマンス
`ab`コマンドで雑に叩く
セレロンの超遅いファイルサーバーマシンで確認

## 非同期

```
Requests per second:    347.96 [#/sec] (mean)
```

## 同期

```
Requests per second:    2830.04 [#/sec] (mean)
```

同期のほうが速いですやん。嘘やん。なんか間違っている気がする。

# 計測大事
同期のほうが速いという状況。よくわからん。ちゃんと計測しないとだめですねー
以上です。