Terminator が起動しない原因を探る

こんにちは、最近趣味でいろんなものをデバッグばかりしている気がする masm11 です。 先日は scp の問題でしたね。

blog.ingage.jp

今回問題だったのは、ターミナルエミュレータ (端末) である Terminator です。

私はデスクトップ環境にボタンを配置し、そのボタンをクリックすると Terminator が 起動するように設定しています。しかし、デスクトップ環境起動後、一度目のボタン クリックは問題ないのに、二度目以降は無反応なのです。これを調べてみました。

調査開始

とりあえず調べるのは標準エラー出力です。以下のエラーが発生していました。

Traceback (most recent call last):
  File "/usr/bin/terminator", line 114, in <module>
    TERMINATOR = Terminator()
  File "/usr/lib/python2.7/site-packages/terminatorlib/terminator.py", line 72, in __init__
    self.prepare_attributes()
  File "/usr/lib/python2.7/site-packages/terminatorlib/terminator.py", line 97, in prepare_attributes
    self.pid_cwd = get_pid_cwd()
  File "/usr/lib/python2.7/site-packages/terminatorlib/cwd.py", line 42, in get_pid_cwd
    system = platform.system()
  File "/usr/lib/python2.7/platform.py", line 1303, in system
    return uname()[0]
  File "/usr/lib/python2.7/platform.py", line 1270, in uname
    processor = _syscmd_uname('-p','')
  File "/usr/lib/python2.7/platform.py", line 1005, in _syscmd_uname
    rc = f.close()
IOError: [Errno 10] 子プロセスがありません

そもそも Terminator は Python 2.7 で書かれているのですね。

例外を見たところ、何故なのかはよくわかりませんが、platform.system() を使って 環境がどんなシステムなのかを取得しているようです。 platform.system() のその奥では uname -p を実行して、パイプ経由で 出力を取得しているのでしょう。その後に子プロセスの終了を待とうとして 例外が発生しているのでしょう。このくらいの情報がこの例外メッセージから得られます。

では、何故子プロセスを作っているにも関わらず、「子プロセスがありません」という エラーが発生するのでしょうか?

プロセスの扱い方

ここで Linux のプロセスの扱い方についておさらいをしましょう。

別プロセスでプログラムを実行するには、以下のようにします。

1. fork() で子プロセスを作る
2. 子プロセスでは exec() でプログラムを実行する
3. 親プロセスでは wait() で子プロセスの終了を待つ (その返り値として、子プロセスが正常に終了したのかどうかが得られる)

親プロセスが wait() しなかった場合、子プロセスが終了しても看取ってくれる プロセスがいないため、子プロセスはゾンビとなります。ゾンビは ps コマンドで見ると defunct と表示されます。 ゾンビを大量に作ってしまうと、カーネルのプロセステーブルが溢れてしまい、 プロセスがそれ以上作れなくなってしまいます。

かと言って、ただ wait() で待っていると、親プロセスは他の処理が何もできません。 それでいいならいいのですが、それでは困ることもよくあります。 そういう場合の回避策がいくつか用意されています。その一つが、SIGCHLD と呼ばれるシグナルです。

• SIGCHLD をデフォルトのまま何も設定しなければ、普通に wait() する必要が あります。
• SIGCHLD にハンドラを設定すると、子プロセスが終了した時に SIGCHLD が発生 し、指定のハンドラが実行されます。その時に wait() してあげます。
• SIGCHLD を無視するように設定すると、子プロセスが終了した時に、ゾンビに ならず、勝手に消滅します。

SIGCHLD 無視って、便利そうですよね。ただ、勝手に消滅するということは、 wait() できないということです。正常終了したのかどうか、判断することが できません。

さて、おさらいはこのくらいにしておきます。

解決編

私はこの症状に1ヶ月程前に遭遇し、Python 自身を適当にいじってエラーにならないように 無理矢理回避して、そのまま忘れていました。最近、Python がアップデートされたことで いじった部分が元に戻り、再び遭遇してしまったので、もう一度調査してみたわけです。

1ヶ月前には SIGCHLD の存在を忘れていましたが、今回の調査で思い出しました。 そうです、デスクトップ環境が SIGCHLD を無視する設定にしていたのです。

問題が起きるまでの流れは以下のようになります。

1. デスクトップ環境を起動する。この状態では SIGCHLD はデフォルト
2. ボタンをクリックする
3. デスクトップ環境内で fork が実行される (この時、SIGCHLD のデフォルト設定が引き継がれる)
4. 子プロセスでは Terminator が実行される (この時は問題なく成功する)
5. 親プロセスでは、wait() したくないし、終了コードも別に要らないので、 SIGCHLD を無視する設定にする
6. もう一度ボタンをクリックする
7. デスクトップ環境内で fork が実行される (この時、SIGCHLD の無視設定が引き継がれる)
8. 子プロセスでは Terminator が実行される

二度目に子プロセスで Terminator が実行された時、そのプロセスは SIGCHLD を 無視する設定になっているので、子プロセスを作って uname -p を実行した後、 その子プロセスはすぐに消滅していたのです。

どういうことか、簡単に図にしてみました (図中の番号と上に書いた項目の番号は無関係です)。

これで、「一度目は成功するのに二度目以降は失敗する」という超不可解な現象が 説明できました。

では、どう修正するのが良いでしょうか? 私の答えは、

• 子プロセスでは、SIGCHLD をデフォルト設定に戻した上で Terminator が実行される

とすることです。これで Terminator が正常に wait() することができます。

まとめ

以上、プロセスの扱い方を含め、調査開始から解決までご紹介しました。

私が使っているデスクトップ環境は同種のソフトウェアの中でもかなりの新参者です。 ですので、全然枯れておらず、いろんなバグに遭遇します。 難しい症状を解決できると、それはもう何とも言えない達成感が得られます。 なかなかに楽しめます。

ではまた!!

@johtani さんと弊社サービスの Elasticsearch について話しました(実装編2)

前回のエントリでは、検索アルゴリズムとしては単純な、でも弊社のサービスにはマッチしている N-gram を採用しているということをお伝えしました 。また Elasticsearch ではどういう設定しているかもお伝えしました。

検索結果のハイライト（highlighting）

今回のエントリはハイライト（highlighting）についてです。 弊社サービスの Re:lation では前述のとおり検索機能があり、検索結果は本文に直接ハイライトをかけてます。

いわゆる Google のようなページ検索・文書検索の場合は、キーワード検索をかけたあと、「文書（ページ）へのリンク」と合わせて「キーワードにマッチした部分およびその前後のテキスト（snippet）」が検索結果として表示されます。その snippet 内のマッチしたワードがハイライトされてるというわけです。

当然、Elasticsearch にもその機能はあります。しかしRe:lationの場合は、Gmail やメールソフトでの検索をイメージしてもわかるとおり、検索結果ページがあるわけではなく、メール一覧に検索にひっかかったメールが表示され、本文を開いた際に検索キーワードがハイライトされていてほしいため、Elasticsearch の機能が使えないのです。

Re:lation での実装

ここはゴリゴリにクライアントサイドで実装しています。 つまり本文内（HTMLドキュメント内）の検索キーワードを探して <span class="search-highlight"> と </span> で囲むという処理を書いているのです。

この方法で基本的には何の問題もありません。

ですが、問題がおこることもあります。

まず問題のないケースを考えてみます。

<div>
インゲージ永田です。<br>
いつもお世話になっております。<br>
<br>
この度はかくがくしかじか・・。<br>
..
</div>

というメールにに「お世話」で検索した際は、以下のようになります。

<div>
インゲージ永田です。<br>
いつも<span class="search-highlight">お世話</span>になっております。<br>
<br>
この度はかくがくしかじか・・。<br>
..
</div>

問題ありません。しかし。

<div>
インゲージ永田です。<br>
いつも<b>お</b>世話になっております。<br>
<br>
この度はかくがくしかじか・・。<br>
..
</div>

極端な例ですが、こんな場合にうまくHTML上でキーワードを見つけられずハイライトに失敗します。

これは今でも残っている課題です。

もし解決方法をご存知の方がいらっしゃいましたらお声をかけてくださればと思います。

複数行 UPDATE で発生するデッドロックを回避する

こんにちは、masm11 です。

今回は、RDBMS で複数行の UPDATE すると割と簡単に起きるデッドロックを回避する方法を探ります。 Rails を用い、RDBMS としては PostgreSQL を使います。

準備

まずは、Rails のプロジェクトを作ります。

rails new proj --skip-bundle
cd proj
sed -i -e 's/sqlite3/pg/g' Gemfile    # sqlite3 を pg に書き換え
bundle install --path=vendor/bundle

PostgreSQL にも DB とユーザを作成します。

createdb -U postgres proj
createuser -U postgres proj

config/database.yml は以下のように設定しました。

default: &default
  adapter: postgresql
  user: proj
  pool: <%= ENV.fetch("RAILS_MAX_THREADS") { 5 } %>
  timeout: 5000

development:
  <<: *default
  database: proj

では、モデルを作ります。

bin/rails g model SampleTable col1   

マイグレーション時にテスト用データも作成してしまいます。

class CreateSampleTables < ActiveRecord::Migration[5.2]
  def change
    create_table :sample_tables do |t|
      t.string :col1

      t.timestamps
    end
    SampleTable.create!([ { col1: '123' }, { col1: '456' } ])
  end
end

マイグレーションします。

bin/rails db:migrate

DB 上のデータを確認してみましょう。

luna:proj % psql -U proj -c 'select * from sample_tables' proj
 id | col1 |         created_at         |         updated_at         
----+------+----------------------------+----------------------------
  1 | 123  | 2020-03-11 07:31:53.594273 | 2020-03-11 07:31:53.594273
  2 | 456  | 2020-03-11 07:31:53.596021 | 2020-03-11 07:31:53.596021
(2 行)

luna:proj % 

ちゃんとできていますね。

デッドロックさせる

さて、次にタスクを作成します。

lib/tasks/sample_task.rb を以下のように作成しました。

class Tasks::SampleTask

  def self.execute

    loop do
      SampleTable.update_all({col1: 'foo'})
      $stdout.print '.'
    end

  end

end

これを読み込ませるため、config/application.rb に以下の設定を追加しました。

    config.autoload_paths += ["#{config.root}/lib"]

実行します。

luna:proj % bin/rails runner Tasks::SampleTask.execute
..............................................................

ここまでは動いていますね。

ではこれを3枚の端末で同時実行します。

/home/masm/t/proj/vendor/bundle/ruby/2.7.0/gems/activerecord-5.2.4.1/lib/active_record/connection_adapters/postgresql_adapter.rb:611:in `exec_params': PG::TRDeadlockDetected: ERROR:  deadlock detected (ActiveRecord::Deadlocked)
DETAIL:  Process 875364 waits for ShareLock on transaction 178082; blocked by process 875263.
Process 875263 waits for ShareLock on transaction 178081; blocked by process 875364.
HINT:  See server log for query details.
CONTEXT:  while rechecking updated tuple (8,3) in relation "sample_tables"
: UPDATE "sample_tables" SET "col1" = 'foo'

起きました。デッドロックです。

SQL としては、上記にあるように、

UPDATE "sample_tables" SET "col1" = 'foo'

を実行しているだけです。

これは、id が 1の行と2の行を、順不同で書き換えているためです。

• 1 をロックして書き換えた後に 2を書き換えるためにロックしようとしているプロセス
• 2 をロックして書き換えた後に 1を書き換えるためにロックしようとしているプロセス

両者が互いに相手を待ってしまうのです。

解決策

これを回避するには、書き換え順序を保証してやる必要があります。 例えば id 順にするのが良いでしょう。

しかし、

      SampleTable.order(:id).update_all({col1: 'foo'})

これでは、

UPDATE "sample_tables" SET "col1" = 'foo' WHERE "sample_tables"."id" IN (SELECT "sample_tables"."id" FROM "sample_tables" ORDER BY "sample_tables"."id" ASC)

となり、SELECT は id 順になるものの、結局 UPDATE 自体は順不同になってしまいます。

SQL としては、

UPDATE "sample_tables" SET "col1" = 'foo' ORDER BY "id" ASC

のようになって欲しいところです。ですが、MySQL では UPDATE に ORDER BY が指定できるそうですが、 PostgreSQL では使えません。

      SampleTable.transaction do
        a = SampleTable.lock.order(:id).update_all({col1: 'foo'})
      end

これだと

BEGIN
UPDATE "sample_tables" SET "col1" = 'foo' WHERE "sample_tables"."id" IN (SELECT "sample_tables"."id" FROM "sample_tables" ORDER BY "sample_tables"."id" ASC)
COMMIT

となってしまいます。.lock が効いていません。サブクエリに FOR UPDATE が付くかと思ったのですが。

      SampleTable.transaction do
        a = SampleTable.lock.order(:id)
        a.pluck(:id)
        a.update_all({col1: 'foo'})
      end

こうすると、SQL は以下のようになります。

BEGIN
SELECT "sample_tables"."id" FROM "sample_tables" ORDER BY "sample_tables"."id" ASC FOR UPDATE
UPDATE "sample_tables" SET "col1" = 'foo' WHERE "sample_tables"."id" IN (SELECT "sample_tables"."id" FROM "sample_tables" ORDER BY "sample_tables"."id" ASC)
COMMIT

id 順にロックして、ロックし終わった後に UPDATE するので、これなら問題ありません。

まとめ

結果として、「ここまでするか?」と思えるようなものになってしまいましたが、PostgreSQL が UPDATE に ORDER BY が使えず、Rails も update_all が悲観的ロックに対応していない現状では、仕方ないのかもしれません。

ではまた!

2進数で循環小数してみる

こんにちは、masm11 です。

時々数学で遊んでみたくなりませんか? というわけで、今回は数学と戯れてみたいと思います。循環小数です。とは言え、ただ実証してみるだけですので、気楽にお付き合いいただければと思います。

循環小数とは

まず、循環小数とは何でしょうか?

見たまんま、循環している小数のことですね。

おそらく「」という書き方が曖昧で数学者の気に食わないのでしょう、これは以下のように書きます。

1 と 3 の上に点を付けて、「以下、1～3 の部分の繰り返しですよー」という意味です。正確です。

では、これを分数で表現してみます。

実は、

なのです。

もちろん、 の場合に限りません。

です。循環している部分を分子に書き、同じ桁数だけ 9 を分母に並べるのです。

ここまでは、もしかすると、「あ、高校の時にやった」という方もいらっしゃるかもしれません。

0.1 を2進数で正確に表現する

「そんなことできるの?w」 いえいえ、上記のように、循環小数を正確に表現できるのですから、できるかもしれません。

ここからは、10進数か2進数かを数値の右下に書きます。 は のことで、 は のことです。

では行きましょう。

ここまでは分数で2進数表記にしただけです。

10進数で分母を 999 の形にすればいいということは、2進数でも 111 の形にすればいいのかもしれません(*1)。

は ですね。これを の形にするにはどうすればいいでしょうか? 分母分子に何かを掛けましょう。, , , ... あ、 が ですね。では を掛けることにします。

最後の は、 を補っただけです。

さて、仮説 (*1) が正しいなら、

です。最後の分数は、 で割ってるだけなので、

となります。

さて、この値が10進数でいくつなのか、Ruby でコードを書いて確認してみました。

sig = 0.25
sum = 0

32.times do |i|
  mod = i % 4
  sum += sig if [2, 3].include? mod
  puts sum

  sig /= 2
end

2進数の一桁ずつ、1 なら sum に加えて、0 なら加えない、それだけのコードです。 結果は以下のようになりました。

0
0
0.0625
0.09375
0.09375
0.09375
0.09765625
0.099609375
0.099609375
0.099609375
0.099853515625
0.0999755859375
0.0999755859375
0.0999755859375
0.0999908447265625
0.09999847412109375
0.09999847412109375
0.09999847412109375
0.09999942779541016
0.09999990463256836
0.09999990463256836
0.09999990463256836
0.09999996423721313
0.09999999403953552
0.09999999403953552
0.09999999403953552
0.09999999776482582
0.09999999962747097
0.09999999962747097
0.09999999962747097
0.09999999986030161
0.09999999997671694

に限りなく近くなっていますね。

0.1 の場合の実証としてはここまでです。

これで、おそらく正確に表現できたのでは、と思います。

一休み

2進数の小数が出てきたので、ついでに説明してみますと、

と、小数点より上が 1 になるように調整して、小数点より上を取り除き、 を浮動小数点の仮数部、 を指数部と呼びます (ただし、wikipedia によると、他にも方式があるようです)。

0.01 の場合

さて、0.1 を2進数で表現した結果はご存知の方も多かったのではないでしょうか。もう一つくらいやってみましょうか。0.01 です。

0.1 の場合と同様にここまで変形しました。 は です。これを何倍かして にしたいのです。

32, 64, 128, 256, 512, 1024, 2048, 4096, 8192, 16384, 32768, 65536

ここまでは頭に思い浮かべながら、違うことが想像できました。16bit 世代にはここらへんが限界です。この先は覚えていません。素直に Ruby の力を借りましょう。

n = 2

loop do
  break if (n - 1) % 25 == 0
  n *= 2
end

puts n
puts (n - 1) / 25

出てきた答えは、

1048576
41943

これは、1M (メガ) ですね。これだけは最近ようやく覚えました。 です。 そして、上の出力結果の通り、 は だそうです。

では、分母分子を 倍しましょう。 なので、

これを 0.1 の場合と同様に Ruby のプログラムで検証します。

0
0
0
0
0.0078125
0.0078125
0.009765625
0.009765625
0.009765625
0.009765625
0.0098876953125
0.00994873046875
0.009979248046875
0.0099945068359375
0.0099945068359375
0.009998321533203125
0.009998321533203125
0.009999275207519531
0.009999752044677734
0.009999990463256836
0.009999990463256836
0.009999990463256836
0.009999990463256836
0.009999990463256836
0.009999997913837433
0.009999997913837433
0.009999999776482582
0.009999999776482582
0.009999999776482582
0.009999999776482582
0.009999999892897904
0.009999999951105565
0.009999999980209395
0.00999999999476131
0.00999999999476131
0.00999999999839929
0.00999999999839929
0.009999999999308784
0.009999999999763531
0.009999999999990905
0.009999999999990905
0.009999999999990905
0.009999999999990905
0.009999999999990905
0.00999999999999801
0.00999999999999801
0.009999999999999787
0.009999999999999787

綺麗に 0.01 に近づいてますね!

まとめ

0.01 ともなると、桁数が多くて、結局、途中の計算も検証も全て Ruby でやってしまいました。

なお、今回のこの記事では、理論的な裏付けなしに仮説 (*1) をでっち上げて使っています。 もし本気の用途に使われる際にはご注意ください。

ではまた!

@johtani さんと弊社サービスの Elasticsearch について話しました(実装編1)

前回のエントリで、弊社サービス Re:lation が Elasticsearch をどういう感じで使っているのかを、主にインフラにまつわる部分を中心に書きました。

blog.ingage.jp

今回は実装に関わる部分を書いてみたいと思います。

前回の記事も含めて今回の記事につきましても、誤っている箇所がありましたら是非ご指摘ください。

形態素解析かN-gramか？

リリース当初は、日本語検索なんだから、 kuromoji っしょ、と思い、 kuromoji を使うことにしました。 kuromoji は形態素解析器です。ドキュメントの本文も、検索キーワードも形態素にわけて検索します（厳密に言えば analyzer の設定次第なんでしょうが）。

しかし問題がおこりました。

「大阪大学」というキーワードで検索すると、「大阪」で検索した結果や「大学」で検索した結果も含まれてしまうのです。メールボックスを検索する上であまりうれしくはありません。当然スコアが高い順に表示したら「大阪大学」で検索したものが上にくると思いますが、感覚的にもご理解いただけると思いますが、メールの検索ではスコア順ではなく最近のメールから表示してほしいです。また、自分のメールボックスを検索する場合は完全一致がうれしいだろうと思います。RDBMSで言うところの LIKE 検索がしたいのです。

そこで N-gram です。N-gram そのものの説明は割愛します。 最低2文字以上で検索するのであれば bi-gram (2-gram) でもいいのですが、1文字で検索したいことはあります。「橘さん」からのメールはとりあえず「橘」で検索したくなるでしょう。Tokenizer は以下のように設定しています。

            tokenizer: {
              message_ngram_tokenizer: {
                type:        "ngram",
                min_gram:    1,
                max_gram:    2,
                token_chars: [ "letter", "digit", "punctuation", "symbol" ]
              }
            }

N-gram を使うメリットとしては、

• LIKE 検索が実現できる
• 未知語については考えなくていい
• kuromoji と違って elasticsearch に内包されている

があり、

デメリットとしては、

• インデックスサイズが大きくなる
• 類義語検索やあいまい検索ができない

があげられると思います。

実は kuromoji を使った場合も EXTENDED という、未知語は uni-gram (1-gram) に分割するという形態素解析とN-gramのハイブリッドのようなモードがあります。 これは当時試してはみましたが、詳しくは忘れましたが思うように検索できないことがあり断念しました。おそらく上述の「大阪大学」のような未知語ではないワードが分割され検索されてしまったのだと思います。

今回のエントリはここまで。

@johtani さんと弊社サービスの Elasticsearch について話しました

@kizashi1122 こと、永田です。

blog.johtani.info

@johtani さんがツイートするもんだから、あいよっと返事してしまいました。

以下、@johtani さんに話したことも話してないこともツラツラと書いていこうと思います

はじめに

弊社のサービスである「Re:lation」はメールやチャットや電話メモなどを一元的に管理できるサービスです。 「そういえば○○なメール来てたはずだけど・・・」などという時のために当然検索は必要になります。RDBMS の LIKE 検索でもいいわけですが、インデックスが効かないしデータが増えるとパフォーマンスがでないのは見えていたので、検索エンジンは専用のソフトウェアを使うべきとは思っていました。当時は世の中では Solr も現役だったのですが、同じ Lucene をエンジンとするミドルウェアでも Elasticsearch が伸びてきているのもあり、Elasticsearch を選択しました。

Elasticsearch on EC2 での運用からスタート

「Re:lation」はリリース当初（2014年）から検索機能はありました。 当時は、Amazon Elasticsearch Service はなく、自前で EC2 上に Elasticsearch を立ててました。最初はなんと1台構成です。余裕でSPOFです。使えなくなるのは検索機能だけですけど。

リリース当時の Elasticsearch のバージョンは当時の最新で v1.3.4 でした。 その後、v1.3.6, v1.7.0, v1.7.1, v2.3.2 とスキを見てはバージョンアップし、その後はだいぶとサボって2018 年の初めに v5.6.5 に上げました。

その頃にはとっくに Amazon Elasticsearch Service がローンチしており（2015年にリリース）、もう十分運用されていることもあり、去年の11月にようやく移行することができました（エンジンのバージョンは v7.1）

Amazon Elasticsearch Service への移行

これはかなり頭を悩ませました。 スナップショットをとって移行すべきか？　バージョンが違うと互換性はどうなるのか？

Bit Journey 社の@michiomochi こと道川さんにも相談しましたが、やはりインデックスを作り直すのがいいだろうということになりました。一からドキュメントのインデクシングをするわけなので、互換性については考慮する必要がないのはメリットです。

つまり旧環境で運用しつつ、新環境（Amazon Elasticsearch Service）にDBからデータをインポートするバッチを流すわけです。当然、運用しながらなので旧環境にしか反映されないデータもあるわけですが、初回のインポートが完了後、データベースと新環境のインデックスの差分をみて、差分があれば吸収するバッチを何度も動かして、同期をとっていきます。ほぼ同期がとれたところで、アプリからの参照先を新環境に向け、その後再度同じバッチを流して完了です。ダウンタイムはありません。

この1からインデックスをつくってデータを流し込み、同期をとっていく作業に3週間くらいかかりました。

インデックス設計

Re:lation はマルチテナント型のウェブアプリケーションです。

blog.ingage.jp

テナントごとに検索できる必要があるわけです。 どうやってインデックスの設計をするかが難しいところです。

最初は、どこかで読んだ「1テナント：1インデックスにすべし」という記事を鵜呑みにして、何も考えずにそうしました。 というかこれで特に問題はありませんでした。なんなら、Github の elasticsearch-rails のリポジトリのイシューに投稿されるこの手の疑問には「1テナント：1インデックスがいいよー」と私が答えてました。

https://github.com/elastic/elasticsearch-rails/issues/321 https://github.com/elastic/elasticsearch-rails/issues/359

ただ、顧客（＝テナント）が増えると当然インデックスも増えてくるわけで、インデックス多すぎ問題が出てきます。 当時で300弱くらいでした。実のところ、インデックスが多すぎによる問題は発生していませんでしたが、今後のことを考え設計を見直しました。 Elasticsearch が管理する対象のインデックスが多くなれば負荷も上がっていくことが予想されます。

次に考えられるのは「データは1インデックスにして、ドキュメントの属性としてテナント識別子を持つ」というやり方です。毎回検索条件にテナント識別子を含めればいいよねという考え方です。

ただデータ量が相当あったので、インデックスは5つにして、テナントは tenant_id で割り振っていくことにしました。シャード数は6だったかな。シャード を限定したアクセスが可能なルーティングという機能があるのを知り、使うことにしました。ルーティングを使えば、エイリアスにルーティング（ _routing ）を含めることができるため、物理インデックスを意識しなくても、検索条件に明示的にテナント情報を含めなくてもアクセスできます。

      actions = [{
        add:
          {
            index: real_index_name,
            alias: alias_name,
            routing: tenant_id,
            filter: { term: { tenant_id: tenant_id } }
          }
      }]
      client.indices.update_aliases(body: { actions: actions })

今は基本的な構成はこの頃から変わってないですが、データ量増加にともない、インデックス数は5ですが1インデックスあたりのシャード数は8としています。（1シャードあたりのデータ量は大きくしたくない）　また今はルーティング機能による高速化は実感できなかったため素直にルーティングは外しました。

      actions = [{
        add:
          {
            index: real_index_name,
            alias: alias_name,
            filter: { term: { tenant_id: tenant_id } }
          }
      }]
      client.indices.update_aliases(body: { actions: actions })

このあたり正解がなく手探りなところが辛いです。

課題

Amazon Elasticsearch Service ではインスタンスストレージが使える i3 シリーズを使っています。インスタンスストレージはEBSのようにネットワーク越しでディスクを使うわけではなく、PCIバスなどによりサーバーに直接つながっているので高速です（ただしディスクサイズは自由に決められなかったり、揮発性であるというリスクはあります）これにより大幅な検索パフォーマンスの改善ができました。お金の力すごい。

ただ、とはいえ検索遅いクエリなどはまだあったりします。ここは問題です。Elasticsearch では「一定時間で検索したところまでを返却する」ということはできますが、ウチの用途ではさすがにこれは許されません。

複数のインデックスへの割り振りは単純に tenant_id でおこなっていると上述しましたが、当然、ヘビーに使うテナントがあるインデックスに偏るということはあります。平準化が難しいです。

大谷さんにはもっと細かい実装時のお話もしましたが、それはまた別のエントリにわけたいと思います。

scp コマンドにまつわる不思議な挙動を追う

こんにちは、masm11 です。

scp で大きなファイルを転送すること、ありますよね。

私も時々やるのですが、今回、ログアウトすると scp が通信しなくなる、 という妙な症状に見舞われましたので、ご紹介します。

症状

状況としては、まず、3台のコンピュータがあります。

A から B に ssh でログインし、scp コマンドを使って C にあるファイルを B にコピーします。

A$ ssh B
B$ nohup scp C:bigfile.tar.gz . < /dev/null >& /dev/null &

こんな感じですね。zsh を使っているので >& を使っていますが、 bash だと2行目は、

B$ nohup scp C:bigfile.tar.gz . < /dev/null > /dev/null 2>&1 &

になるでしょう。

そして、B の bigfile.tar.gz が大きくなっていくのを以下のようにして 見ていました。

B$ watch -n 1 ls -l bigfile.tar.gz

こうすると、一秒おきに、画面をクリアして ls -l bigfile.tar.gz を実行してくれます。

さて、この後、ひょんなことから、A の端末が落ちてしまいました。

まぁそんなことはよくあることです。 気を取り直して、再び B に ssh して watch コマンドを実行してみたところ、 ファイルサイズが大きくなっていかなくなっていました。

nohup を付けていたのに、scp コマンドが終了してしまったのか? と思い、 ps auxww | grep scp してみたところ、プロセスは生きていました。 B でも C でも確認しました。

プロセスが残っているのに、データが転送されなくなっています。

コネクションが詰まってしまったのでしょうか? B で scp コマンドを kill で殺したところ、C でも scp プロセスがいなくなりました。 コネクションには問題なかったようです。

以上をもう一度試してみたところ、完全に再現しました。再現性はあるようです。

検証

いくつか気になる点がありますので、列挙してみます。

• nohup はちゃんと仕事をしているのか?
• SIGHUP を本当に受け取ったのか?
• scp は独自の SIGHUP ハンドラを設定しているのか?
• scp は SIGHUP を受けて何かするのか?
• scp は止まった状態で何をしていたのか?
• scp のマニュアルに記載はあるか?
• この症状に zsh は関係するのか?

以下、これらを一つずつ調べていきます。

nohup はちゃんと仕事をしているのか?

nohup を付けると、以下のように出力されますよね。

luna:/tmp % nohup ls
nohup: 入力を無視し、出力を 'nohup.out' に追記します
luna:/tmp % 

標準入力は /dev/null になり、標準出力、標準エラー出力は nohup.out になります。

しかし、nohup の仕事はこれだけではありません。 SIGHUP という signal を無視するようにする、という重要な仕事があります。

これが行われているのかどうかを確認してみました。

C で以下のコードを書きます。

#include <stdio.h>
#include <signal.h>

static void handler(int signo)
{
}

int main(void)
{
    printf("%p\n", signal(SIGHUP, handler));
    return 0;
}

signal() 関数は、新しい signal ハンドラ を設定すると共に、 旧 signal ハンドラを返してくれますので、その値を出力します。

これを test.c というファイル名で保存し、コンパイル、実行してみます。

すると、以下のように出力されます。

luna:~ % ./test 
(nil)
luna:~ % 

では nohup を付けてみます。

luna:~ % nohup ./test 
nohup: 入力を無視し、出力を 'nohup.out' に追記します
luna:~ % cat nohup.out
0x1
luna:~ % 

0x1 ですね。これが何かと言うと、

luna:~ % grep SIG_IGN /usr/include/bits/signum-generic.h
#define    SIG_IGN  ((__sighandler_t)  1)  /* Ignore signal.  */
luna:~ % 

これです。signal を無視する設定 SIG_IGN の値は 1 なのです。 これが出力されたんですね。

このように、nohup は

• 標準入力を /dev/null にする
• 標準出力、標準エラー出力は nohup.out にする
• SIGHUP を無視するようにする
• これらを設定した上で、指定されたプログラムを実行する

という仕事をしているのです。

問題ないようですね。

SIGHUP を本当に受け取ったのか?

signal を受け取ったかどうかを確認するには、strace を使うのが手っ取り早いです。

B$ strace -f -o log nohup scp C:bigfile.tar.gz . < /dev/null >& /dev/null &
[1] 732184
B$

こうすると、strace の子孫プロセス全てにわたって (-f)、システムコールの状況が log ファイルに (-o log) 出力されます。また、signal を受け取った時はその signal 番号も出力してくれます。

出力から一部を抜き出すと、以下のようになっていました。

732460 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732179, si_uid=1000} ---
732460 select(7, [3 4], [], NULL, NULL <unfinished ...>
732459 <... poll resumed>)              = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
732459 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732179, si_uid=1000} ---
732459 kill(732460, SIGHUP)             = 0
732460 <... select resumed>)            = ? ERESTARTNOHAND (To be restarted if no handler)
732459 wait4(732460,  <unfinished ...>
732460 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732459, si_uid=1000} ---

確かに SIGHUP を受け取っているようです。 SIG_IGN に設定されていると、

732460 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732179, si_uid=1000} ---

という出力はないはずだからです。

scp コマンドが独自の SIGHUP ハンドラを設定しているのでしょうか?

scp は独自の SIGHUP ハンドラを設定しているのか?

これについては、先程の strace のログをもう一度見てみましょう。ログの上の方に、

732459 rt_sigaction(SIGHUP, {sa_handler=0x556e9127d810, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f4df345cfb0},  <unfinished ...>

こんな行がありました。sa_handler= がいかにもプログラムの中っぽいアドレスになっています。

どうやら、自前のハンドラを設定しているようです。 これでは、nohup を付けても意味はないですね。

scp は SIGHUP を受けて何かするのか?

これについては、多少推測する程度しかできません。

先程の strace のログを再度引用すると、

732460 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732179, si_uid=1000} ---
732460 select(7, [3 4], [], NULL, NULL <unfinished ...>
732459 <... poll resumed>)              = ? ERESTART_RESTARTBLOCK (Interrupted by signal)
732459 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732179, si_uid=1000} ---
732459 kill(732460, SIGHUP)             = 0
732460 <... select resumed>)            = ? ERESTARTNOHAND (To be restarted if no handler)
732459 wait4(732460,  <unfinished ...>
732460 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=732459, si_uid=1000} ---

おそらく scp は2つのプロセスで成り立っていて、732459 が親プロセス、732460 が子プロセスです。 そして、732459 が SIGHUP を受け取った後、kill(732460, SIGHUP) で 732460 に SIGHUP を送って います。

つまり、親プロセスが SIGHUP を受け取ったら、それを子プロセスにも送る、ということですね。 よくある構造です。

その他にも何かやっているかもしれませんが、これ以上は判りませんでした。

scp は止まった状態で何をしていたのか?

これもほとんど手がかりはないのですが、

B$ ss -n | grep :22 
tcp     ESTAB        0        0                         192.168.86.132:36134                       x.x.x.x:22
tcp     ESTAB        0        0                         192.168.86.132:22                         192.168.86.150:51614
B$

ソケットのバッファに何も溜まっていません。このことから、そもそも送信側 (C) が送ってなさそう、と考えられます。

scp のマニュアルに記載はあるか?

http://man7.org/linux/man-pages/man1/scp.1.html

ここにマニュアルがあります。このページから hup や signal でページ内検索してみましたが、引っかかりません。 記載はないようです。

https://linux.die.net/man/1/ssh

こちらに ssh のマニュアルがあります。scp は ssh を使っているので、もしや、と思いましたが、 こちらにも記載はありませんでした。

この症状に zsh は関係するのか?

man zshall して SIGHUP で検索してみたところ、記載がありました。 引用します。

       When  you  try  to leave the shell while jobs are running or suspended,
       you will be warned that `You have suspended (running) jobs'.   You  may
       use  the  jobs command to see what they are.  If you do this or immedi‐
       ately try to exit again, the shell will not warn you a second time; the
       suspended  jobs will be terminated, and the running jobs will be sent a
       SIGHUP signal, if the HUP option is set.

zsh を終了しようとした時、実行中のジョブには SIGHUP が送られるようです。 ただし、HUP オプションがセットされている場合。だそうです。

解決策 (回避策)

さて、ここまでいくつか検証してみた結果、

• nohup は仕事をしているが、
• scp が独自のハンドラを設定している。
• zsh を抜ける時に SIGHUP が送られ、
• SIGHUP を受け取った scp は
• 独自のハンドラで何らかの処理を行い、
• その結果、何故か転送が止まってしまう

ということがわかりました。

何故転送が止まってしまうかについては、マニュアルにも記載がなく、わかりませんでした。

しかし、ここまでわかれば回避はできます。

B で、zsh に

B$ unsetopt HUP

と設定すれば、zsh 終了時に SIGHUP が送られることはなくなります。

また、間に端末 (tty) を挟まなければ OK のはず、と思ったので、

A$ ssh B nohup scp C:bigfile.tar.gz . < /dev/null >& /dev/null &

これでも回避できました。ssh はコマンドラインに直接コマンドを書けば、 tty なしでコマンドを実行してくれます。

私が回避した時には、zsh が絡んでいるとは思っていなかったので、後者の方法で回避し、 以下のように問題なく最後まで転送できました。

B$ ls -l bigfile.tar.gz 
-rw-r--r-- 1 masm masm 2750186558  2月  9 21:04 bigfile.tar.gz
B$

(たかが 3GB 弱です。ネットワーク遅いと萎えますよね…)

まとめ

結局、回避はできましたが、根本的に通信だけ止まっている原因は不明のまま残ってしまいました。 今後解決できるといいのですが…

ではまた！