事象
とある方向けの社内Webアプリ。
OpenMediaVaultのNginxでRailsを動かす、というごくごく一般的な構成。
あるときから長めの処理を行うページが動かなくなった。
具体的な事象は
- ブラウザで操作すると「サーバーとの接続が予期せず解除されました」みたいな感じになる
- curlで叩いても「Empty reply from server」
- 処理時間によっては問題なく成功する
（結構大きいファイルを変換する処理だったので、最初はアップロードまわりかと思ったがそうでもなく単純に長い処理をnginxが待ってくれない、という状態だった。）
nginx/error.logを参照した
-
*14 client closed connection while waiting for request, client: -.-.-.-, server: 0.0.0.0:3003(ipはマスク済み)のエラーがある - ↑のあとに
*4 open socket #25 left in connection 13,abortingと出ている - ネットで探してもよくみるupstream関連のエラーじゃなさそう
- debugレベル有効にしてもこれといった追加情報は得られず
timeout伸ばす
ごくごく一般的なtimeout設定を伸ばした
proxy_connect_timeout 10;
proxy_send_timeout 10;
proxy_read_timeout 60;
例としてこのへん（実際はもっと長い時間にした）
が、解決せず（関係なさそうなtimeout項目は全部入れたが変わらず）
upstreamとのkeep-alive
debugのログをみているとproxy headerにConnection: closeとあった。
upstreamとでkeep-aliveになってないのか？と思い、以下を設定。
ocation / {
proxy_http_version 1.1;
proxy_set_header Connection "";
.....
}
確かにヘッダは変わったが、事象は解決せず…
ここでunix socketのタイムアウトがあったりするのか？など、TCPコネクションまわりを調べてみる。
確かに設定自体はあるのだが、社内アプリくらいなのでアクセスが大量にあるわけではない。
linux自体の設定も十分にあり、これも解決には至らず。
- 参考にさせていただきました）https://qiita.com/SenriQ/items/eaa44d961f6022284d36
- https://unix.stackexchange.com/questions/717952/tcp-timeouts-in-nginx
なお、fileを開く数の制限なども疑ったがこれも空振り
pumaの設定も漁ったがこれも同じく空振り…
犯人候補:systemd
ここでnginxのprocessを見ていて、pidが頻繁に変わっていることに気づいた。
worker processの再起動タイミングが早いのか？と思ったがnginxにその設定は特に無い（していない
サービスが定期的に再起動されてる？ということはsystemdまわり？
と思い、nginx serviceの定義を見てみる。
[Unit]
Description=The NGINX HTTP and reverse proxy server
After=syslog.target network.target remote-fs.target nss-lookup.target
[Service]
Type=forking
PIDFile=/run/nginx.pid
ExecStartPre=/usr/sbin/nginx -t
ExecStart=/usr/sbin/nginx
ExecReload=/bin/kill -s HUP $MAINPID
ExecStop=/bin/kill -s QUIT $MAINPID
PrivateTmp=true
[Install]
WantedBy=multi-user.target
あるはずの「Restart」の項目がない…
ということはsystemdでは再起動していない？
犯人はmonit
service nginx statusで見ていると確かに１分くらいで再起動されていた。
ここでjournalctl -xeでログを見てみろ、と天啓
見た。
openmediavault monit[1343]: 'nginx' failed protocol test [HTTP] at [127.0.0.1]:443 [TCP/IP TLS] -- HTTP>
openmediavault monit[1343]: 'nginx' trying to restart
openmediavault monit[1343]: 'nginx' stop: '/bin/systemctl stop nginx'
openmediavault systemd[1]: Stopping A high performance web server and a reverse proxy server...
Subject: A stop job for unit nginx.service has begun execution
Defined-By: systemd
Support: https://www.debian.org/support
A stop job for unit nginx.service has begun execution.
The job identifier is 2826996.
あった…
どうやらmonitがHTTPの疎通に失敗して再起動をかけていた様子。
確かにサーバー上でlocalhostにcurl打ったら403になる。
ここで思い出す。nginxの海外IPアクセス制限を入れたことを。
自分自身のipもブロックしていたので、monitの監視に失敗してnginxを再起動させていた。
ということで真犯人は自分だった
教訓
- もともと入ってるservice使わずにおとなしくDocker使う
- トラブルはjounalctl見るのが一番早い