error An unexpected error occurred: "EPROTO: protocol error, symlink

N予備校のプログラミング入門Webアプリコースの話題です。
環境はWindows8.1です。
※非推奨環境です。

サーバーサイドプログラミング入門で以下のエラーが発生しました。
vagrant@ubuntu-bionic:~/workspace/hubot-todo$ yarn add ../todo
yarn add v1.21.1
[1/5] Validating package.json...
[2/5] Resolving packages...
[3/5] Fetching packages...
[4/5] Linking dependencies...
error An unexpected error occurred: "EPROTO: protocol error, symlink '../../../sshpk/bin/sshpk-conv' -> '/home/vagrant/workspace/hubot-todo/node_modules/http-signature/node_modules/.bin/sshpk-conv'".
info If you think this is a bug, please open a bug report with the information provided in "/home/vagrant/workspace/hubot-todo/yarn-error.log".
info Visit https://yarnpkg.com/en/docs/cli/add for documentation about this command.
yarnコマンドに--no-bin-linksオプションをつけることでエラーをつけて回避できます。
このオプションの意味を私は理解していませんが、課題達成は問題なくできます。
vagrant@ubuntu-bionic:~/workspace/hubot-todo$ yarn add ../todo --no-bin-links
yarn add v1.21.1
[1/5] Validating package.json...
[2/5] Resolving packages...
[3/5] Fetching packages...
[4/5] Linking dependencies...
[5/5] Building fresh packages...
success Saved lockfile.
success Saved 1 new dependency.
info Direct dependencies
└─ todo@1.0.0
info All dependencies
└─ todo@1.0.0
Done in 1.41s.
エラーの解消にあたって、Windows環境でnpm installでエラーが発生する場合の対処法を参照いたしました。


pgpoolのlog_destination

この話題は、pgpoolとCentOS8の話です。

pgpoolの設定の一つである「log_destination」はログの出力先を指定します。
設定値は、「stdder」、「syslog」、「stdder,syslog」の3種類です。

log_destinationを「stdder,syslog」に設定し、rsyslog.confをそれなりに設定し、これで/var/log/pgpool/pgpool.logにだけログが出力されると思ったら、/var/log/pgpool/pgpool.logにも、/var/log/messagesにも出力されていました。
log_destinationを「syslog」に設定して、思ったとおりの動作になりました。

「stdder,syslog」と設定すると、pgpoolはstdderにもsyslogにもログを出力します。
stdderに出力されたログは、systemdがjournaldに渡します。
journaldは渡されたログをrsyslogdに渡します。
# cat /etc/rsyslog.conf
<中略>
module(load="imjournal"             # provides access to the systemd journal
       StateFile="imjournal.state") # File to store the position in the journal

log_destinationを「stdder,syslog」に設定すると、「syslog」の設定がrsyslogd経由でログを書き込み、「stdder」の設定が、journald→rsyslogd経由でログを書き込む、動作になります。

log_destinationを「syslog」にしてログを保存する場合の設定は公式マニュアル、「stdder」にしてログを保存する場合はpgpool logging on centos 7 | Pierre Timmermansを参照するといいと思います。

ErogameScapeを17年間自宅サーバーで運用してみて

ErogameScapeは自宅サーバーだったのですが、先日、専用サーバーを借用して移管をしました。
自宅サーバーにしたのが2003年4月27日だったので、17年間くらい自宅サーバーを運用してきました。

後から、ああ、こんなことあったなあ…、と思い出にひたるために記録に残しておきます。

(1)レンタルサーバーから自宅サーバーに切り替える
ErogameScapeを作った当初はレンタルサーバーで動かしていました。
そのレンタルサーバーは2001年時点でPostgreSQLが使えるというとても先進的なサーバーでした。
2001年のことですから、PostgreSQLでサービスをするWebアプリを作る人は少なく…、そのサーバーのリソースは私が独り占め状態でした。
ある日、phpで無限ループするスクリプトをレンタルサーバーにあげてしまって、サーバーを落としました。当然、怒られました…
少し経って、また同じミスをして、サーバーを落としました。今度は、サーバーを出ていってくれと言われました。さあ大変…
PostgreSQLが使えるレンタルサーバーは他に選択肢がなく、自宅サーバーにすることにしました。

(2)上り帯域が足りない
ErogameScapeは基本テキストのデータしか扱っていないので帯域はとても少なくて大丈夫です。
当時の自宅サーバーの回線はADSLでした。
ADSLの上り帯域は1Mbpsでしたが、サービス開始当初はこれで問題ありませんでした。
しかし、2004年頃、帯域が足りなくなって、ADSLモアIII(上り5Mbps)に変更しました。
帯域が出るかはNTTの局舎からの距離によるので、おそらく賭けだったと思うのですが、確かちゃんと帯域は出て問題は解決した…はずです。
このとき、帯域が足りなかったので、一時的にコンテンツをレンタルサーバーに退避していますが、ADSLモアIIIへの切り替え後、元に戻しています。
ちなみに今でもErogameScapeは平均すると1Mbps/sで足りております。

(3)IPマスカレードのセッション数が足りない
2005年、当時使っていたADSLルータのBBR-4HGのIPマスカレードのセッション数が足りない事象が発生していました。
BBR-4HGのセッション数は800でした。
どうやって「IPマスカレードのセッション数が足りない」ことを知ったのかの記録をおったら、モデムとADSLルータの間にスイッチング機能を持たないハブをいれてパケットをキャプチャし、トラヒックが高くなる時間にルータがたくさんRST ACKを返していることから推測したようです。
そういえば当時の自分は切り分け用にハブを持っていました…
ユーザーさんに対策を相談し、XR410/TX2(4万円)かRTX1000(ヤフオクで4万円)を勧められました。
高い…
セッション数の問題であれば、セッション数が潤沢な安いADSLルータを相談し買えばいいと思い、BLR3-TX4(セッション数4096)を買うも問題解決せず…
結局、XR410/TX2を買いました。
XR410/TX2は大変素晴らしくEOLまで使いました。
この時、学んだのは「カタログスペックはあてにならない」「高いものはいい」です。

(4)XR410/TX2が踏み台にされる
サーバーの設定を確認して問題ないと思っていたらプロバイダから
この度、外部より、ご提供しておりますインターネット接続回線に
割当てのIPアドレス「XXX.XXX.XXX」から、NTPを利用した大量の通信
(DDoS攻撃)が発生しているとの連絡を受けております。
との連絡が来て青ざめました。
連絡を受けた時は、何が原因なのかさっぱり見当がつかなかったのですが、サーバーは確認していたけど、そういえばネットワーク機器は確認していなかった…ということで、XR410/TX2のNTPDを止めてDDosが収まりました。
ネットワーク機器もちゃんと確認しなくてはいけない…と思った次第でした。

(5)FedoraからCentOSにする
2011年まで、Fedoraを使っていました。
2011年にCentOSの存在を知りCentOS6に移行しています。
それまではFedoraは1年に1回アップデートしていた(今もそうなのかな?)ので、1年に1回、OSを再インストールしていました。
2008年まではサーバーのスペック不足のため1年に1回新しいPCを買っていたので、ついでに新しいOSを入れるのは問題なかったのですが、後述するとおり2009年を最後に新しいPCを買わなくなったので、OSのインストール面倒…というところでした。
CentOSにしたら、OSのインストールをすることはなくなったので、作業量は激減したのですが、次のOS更改の際に自分は対応できるのだろうか…と不安を抱えることになります。

(6)スペックが足りないのでだいたい1年に1回サーバーをリプレイス(2008年まで)
当時は時間をおうごとに着々と負荷があがっており、ソフト的な対策(キャッシュできるところはキャッシュするとか)やハード的な対策(pgpoolを導入して2台で負荷分散)をしていたのですが、おいつかないので、1年に1回PCを買っていました。
しかし2008年を最後にリプレイスしなくてよくなりました。
買ったPCの構成は以下のとおりです
Storm Metaphor 64 LTD
 Core 2 Quad Q9550
 ASUS P5Q(Intel P45 + ICH10R IEEE GbLAN)
 Winchip/DDR2-800 16GB(4GBx4)
 GeForce 8400GS 256MB PCI-Express x16
 WesternDigital WD Caviar Green WD10EADS(1TB SATA-3Gb/s 32MB)
 Seagate Barracuda 7200.12 ST31000528AS(1TB SATA-3Gb/s 7200rpm 32MB)
 KURO600G(静音)
これの1つ前のマシンはメモリが少なかった(6G)のですが、メモリを思い切って16GBにしたら負荷ががくっと下がった…と思われます。
「データベースは使う内容がメモリにすべてのる」ことが肝ですが、当時の自分はそんなことはまったく知らなかったので、16GBのすごさを思い知りました。
この後、同じスペックのPCをもう1台買って、冗長構成になりました。

(7)引っ越し
自宅サーバーなので引っ越しをするたびにサーバー一式を移動させる必要があります。
最初の引っ越しのときは、自宅サーバーしかなかったので、旧居でサーバーを落とし、新居に一式を持っていき、立ち上げ、まではサービス中断でした。
その後の引っ越しはバックアップ用の専用サーバーを借りていたので、一時的に専用サーバーを現用にして、引っ越しが終わったら自宅サーバーに戻す、ということをしていました。
引っ越しで一番怖かったのは、電源を入れたときにちゃんと起動するか、でした。
電源を落とすと、なぜか起動しない…というのはよくあることで、切り分けが大変でした。
たいてい、がちゃがちゃやってるうちに起動するのですが…

(7)東日本大震災の計画停電
自宅サーバーの最大の危機がやってきました。電気がきません…
しかし、自宅サーバーのある地区が計画停電から外れていたためサービスを止めなくてすみました。
こんなこともある…ということが分かったので大容量の無停電電源装置BN220Sを買いました。
UPSの本来の用途と違うのですが…3時間程度なら耐えられる容量です。
ただ、このUPS欠点が2つありました。
  • めちゃくちゃ重い(自分は持てないので引きずるしかない)
  • ファンがうるさい(BATT駆動になると冷却のためFANが24時間回る)
この後、これでは根本対策にならないし、そもそも自宅が壊れたらBAD ENDだ、ということで2012年にさくらインターネットに専用サーバー借りて、バックアップとすることにしました。
ちなみに、それまでのバックアップは定期的にDVD-Rにデータを焼いて実家に送る、実家にはサーバーに使えるPCが1台置いてある…という態勢でした。

(9)ハード故障
(9)-1 PCのケースファンが壊れた
PCのケースファンが大きな音をたてるようになったので電源を抜きました。その後、冬だから大丈夫かなと思って、ファンを回さずに運用したら、全然大丈夫ではなく、温度異常でサーバーが落ちました。
この後、ファンの回転速度、温度を計測するmuninのプラグインを導入しつつ、ケースFANの予備を配備しました。

(9)-2 M/Bが壊れた
切り分けのために最小構成にしても立ち上がらず、CPUを買ってきて交換するも立ち上がらず、M/Bが原因と分かり…M/Bを別のものに交換するとOSの再インストールになっちゃうし、それはきつい…ということで、秋葉原で同じM/B探して見つけて交換ました。お値段は中古だけど新品とあまりかわらない価格ですが…しょうがない…

(9)-3 HDDが壊れた
RAID1なので、1つ壊れても大丈夫。
なのですが、手順を誤ると、データが入っている方を壊してしまうので、昔練習した手順書を探して、えーと、あー、どうやったっけ…と思い出しながら作業。

(9)-4 ネットワークスイッチが壊れた × 2回
自分の経験上、機器が壊れる時は人間が想像もしないような動作をするのですが、自宅サーバーに接続されていたネットワークスイッチも同様で被疑がネットワークスイッチだ!とたどり着くまでに時間がかかったと記憶しています。確か、NICが悪いと思って、NICを交換したけど回復しなくて頭をかかえた気がします。スイッチを介してpingを飛ばすとpingのlossが半端なかったと記憶しています。
ネットワークスイッチは壊れても、電気屋にいけばすぐ買えるので、予備は持っていなかったのですが、安いから買っておこう…ということで予備を購入しました。
購入してからは壊れることはありませんでした…

自宅サーバーの場合「予備をもっておくか」が悩ましいところです。
理想は、1台PCを買ったら、同じ構成のPCをもう1台買って予備にする…だと思うのですが、お金かかりますし…、でもマザーボードが故障して別のものと交換するOSの再インストールになっちゃうのでマザーボードは予備として欲しいかな…今、もし自宅サーバーをたてるなら買うかな…と思います。
また単一障害点となるXR410/TX2が壊れたら同じものを買うまでサービス中断になってやばい、と思ってもう1台同じものを買って所持していました。


自宅サーバーを運用していると、いろんな事案が発生し、都度ググったり、ユーザーさん意見を聞いて、乗り切ってきましたが、「1人では圧倒的に技術も情報も時間も足りない」と思います。

今はレンタルサーバーもVPSもクラウドも低コストで借りられるのでWebアプリを自宅サーバーで動かすメリットはないかな…と思います。自宅サーバーを保守する時間をWebアプリを開発する時間にあてた方がいいと思います。

Apache + pgpool + PostgreSQLで、Apacheがtimeoutで504を返すとき、PostgreSQLのクエリが残ったままになる

この文書はApache2.4.37とPostgreSQL11.7とpgpool4.1.1の話題です。

Apache + pgpool + PostgreSQLで、Apacheがtimeoutで504を返すとき、PostgreSQLのクエリが残ったままになることがあります。

ErogameScapeのApacheはtimeoutを120秒に設定しています。
時間のかかるクエリを実行して120秒を超えてしまうとApacheは504を返します。
このとき実行されたクエリがpsコマンドで見ると実行されっぱなしになっているように見えます。
[ap2@sakura ~]$ ps ax | grep 28908
 8134 pts/0    S+     0:00 grep --color=auto 28908
28908 ?        Ss     0:00 postgres: ap2 ap2 127.0.0.1(55878) UPDATE
このPostgreSQLのプロセスに対応するpgpoolのプロセスを確認するとidleまたはidle in transactionになります。
[ap2@sakura ~]$ ps ax | grep 27546
 8121 pts/0    S+     0:00 grep --color=auto 27546
27546 ?        S      0:00 pgpool: ap2 ap2 127.0.0.1(58634) idle in transaction
このまましておくと、PostgreSQLのクエリがテーブルをロックしたままになってしまっているので、pgpool + PostgreSQLの構成においてテーブルをロックしているPostgreSQLのSQLをキャンセルしたいの記事の方法でpgpoolのプロセスを殺します。

なぜこのような状態になってしまうのか分かりません…
解決方法は、Apacheのtimeoutの設定をのばす、クエリを見直してtimeout以内に収まるようにする、なのですが、根本的な解決方法ではないので困っております。

AH01974: could not connect to OCSP responder 'ocsp.int-x3.letsencrypt.org'

2020年5月11日に以下のログを出力してApacheの応答がなくなりました。

ssl_error_log(httpsのログ)
[Mon May 11 22:39:55.882100 2020] [ssl:error] [pid 2958:tid 139861633783552] (70007)The timeout specified has expired: [client XXX.XXX.XXX.XXX:50024] AH01974: could not connect to OCSP responder 'ocsp.int-x3.letsencrypt.org'
[Mon May 11 22:39:55.882130 2020] [ssl:error] [pid 2958:tid 139861633783552] AH01941: stapling_renew_response: responder error
[Mon May 11 22:40:21.628254 2020] [ssl:error] [pid 2958:tid 139859972847360] (70007)The timeout specified has expired: [client XXX.XXX.XXX.XXX:50027] AH01974: could not connect to OCSP responder 'ocsp.int-x3.letsencrypt.org'
[Mon May 11 22:40:21.628282 2020] [ssl:error] [pid 2958:tid 139859972847360] AH01941: stapling_renew_response: responder error
以下、同じようなメッセージがいっぱい
error_log(httpのログ)
[Mon May 11 22:44:56.103651 2020] [mpm_event:error] [pid 13276:tid 139863211641088] AH00484: server reached MaxRequestWorkers setting, consider raising the MaxRequestWorkers setting
原因はログのとおりOCSP responderであるocsp.int-x3.letsencrypt.orgに接続できないためでした。
ocsp.int-x3.letsencrypt.orgに接続できないのは、nftablesでocsp.int-x3.letsencrypt.orgを含むネットワークからのパケットブロックしていたのが原因でした。
ct state related,established counter acceptの位置の記事のとおり、nftablesの設定を修正し解決しました。
記事検索