OTOBANK Engineering Blog

オトバンクはコンテンツが大好きなエンジニアを募集しています!

転ばぬ先のstrace

こんにちは。@kalibora です。 私は職業プログラマー歴20年弱になるのですが、 数年に一度くらいの割合で strace のお世話になることがあります。
今日はそんな話をしたいと思います。

といっても、strace の挙動についての深い話は一切ないので、 対象者としては strace というものを知らない、もしくは名前は知っているが使ったことがないようないわゆる #駆け出しエンジニア のような方に読んでいただければ幸いです。

strace とは

そもそも strace とはなんでしょうか。wikipedia を引用します。

straceはLinuxのデバッグユーティリティであり、プログラムが使用するシステムコールおよび受け取るシグナルを監視するものである。

strace - Wikipedia

だ、そうです。

man を引いてみましょう。

$ man strace
*snip*
NAME
       strace - trace system calls and signals
*snip*

やはり、システムコールとシグナルをトレースする。と出てきました。

ここでシステムコールとはなんぞや。という疑問も出てきたかもしれません。 再度 wikipedia を引用します。

システムコール(英: system call、日: システム呼出し[1][2][3])とは、オペレーティングシステム (OS)(より明確に言えばOSのカーネル)の機能を呼び出すために使用される機構のこと。実際のプログラミングにおいては、OSの機能は関数 (API) 呼び出しによって実現されるので、OSの備える関数 (API) のことを指すこともある。

システムコール - Wikipedia

というわけで、ざっくりいうと、 strace は OS の機能呼び出しをトレースするものだと言えると思います。

よくわかりませんね。実際に使ってみましょう。

strace 使ってみる

まずは hello strace と表示するだけのコマンドを適当な linux 上で打ちます。
言語は何でもいいんですが、ここでは PHP を使いたいと思います。

$ php -r 'echo "hello strace\n";'
hello strace

表示されました。これに strace をかましてみます。 先程のコマンドの前に strace を入れるだけでOKです。

$ strace php -r 'echo "hello strace\n";'
*snip*
munmap(0x7fd31e600000, 2097152)         = 0
munmap(0x7fd320c67000, 323584)          = 0
exit_group(0)                           = ?
+++ exited with 0 +++

上記と表示は異なるかもしれませんが、ずらずらーっと謎の文字列が表示されるかと思います。 細かく内容を見ていきたいので less をつないで見てみます。(エラー出力に出るので 2>&1 します)

$ strace php -r 'echo "hello strace\n";' 2>&1 | less

いろんな文字列がたくさん出ていると思うのですが、その中に下記のような表示も見つかると思います。

write(1, "hello strace\n", 13hello strace
)          = 13

この行が実際に hello strace と画面に表示するための OS への機能呼び出しです。

はい。これが strace の機能です。

といっても、これが一体何の役に立つのだろうと思いませんか。 次節から実際に私が strace に助けられたケースを書いていきたいと思います。

ケース1: 自分の書いたテストは悪くないはずなのに・・

私がある機能を実装し、それに対するテストも追加し GitHub に push したところ、 その後の Circle CI 上でのテストがエラーになってしまいました。

エラーの内容を確認すると

Too long with no output (exceeded 10m0s): context deadline exceeded

と出ており、テスト(この時は phpunit )実行時に10分間何の出力もないためエラーになったようです。

自分が追加したテストでそんなに変なことはしていないはずなので、
Circle CI に ssh 接続し、色々とデバッグを試みたところ、 追加したテスト単体で実行すると成功、そのテストを含むディレクトリをまるごと実行しても成功、しかしテストスイート全体を実行すると同じエラーで止まる。といった状態でした。

正直何が原因かまったく心当たりがなかったので strace を install し

$ strace ./vendor/bin/phpunit ...

のように、 テストコマンドを strace してみることにしました。 すると、

sendto(151, " \0\0\0\3TRUNCATE hoge_table"..., 36, MSG_DONTWAIT, NULL, 0) = 36
poll([{fd=151, events=POLLIN|POLLERR|POLLHUP}], 1, 86400000

のように、 TRUNCATE のSQLで MySQL から反応が返ってこない事がわかりました。

さらに mysql-client を install し、MySQL クライアント上で show processlist; したところ、 Waiting for table metadata lock が原因で反応が返ってきてこないこと、 たくさんコネクションが張られ続けること、などが分かりました。

これらの状況から、各テストコードで MySQL に接続したまま、それが閉じられていないことが原因と推測し、各テストコードでテストが終わったら接続を切るようにしたところ問題が解決しました。

ケース2: 終わらぬバッチ処理

いつもは数時間で終わる日次で実行しているバッチ処理があるのですが、それが数日経っても終わっていないということがありました。

まずは ps コマンドで該当のバッチ処理が存在し続けていること、プロセスIDを確認し、 該当のプロセスに対し strace コマンドを実行してみました。

-p オプションを使うと、処理中のプロセスに対しても strace をかけることが可能です。 (下記はプロセスID: 2354 に対して strace しています)

$ sudo strace -p 2354
strace: Process 2354 attached
*snip*
poll([{fd=11, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f24ff97e390}, NULL, 8) = 0
poll([{fd=11, events=POLLIN}], 1, 1000^Cstrace: Process 2354 detached
 <detached ...>

上記はその時の結果なのですが、その中の下記の表示、

poll([{fd=11, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)

fd=11(ファイルディスクリプタ=11) をpollしている(イベントを待っている)が、それがタイムアウトしているようでした。

ファイルディスクリプタ=11 の中身が何なのかを調べるには lsof コマンドを使います。 -p でプロセスID, -d でファイルディスクリプタを指定します。-a は AND 条件を表します。 (下記は一部表示を****でマスキングし、IPアドレスもダミーのものです)

$ sudo lsof -p 2354 -a -d 11
COMMAND  PID   USER   FD   TYPE   DEVICE SIZE/OFF NODE NAME
php     2354 ****   11u  IPv4 22163744      0t0  TCP ****:40922->192.0.2.1:https (ESTABLISHED)

このように表示され、3rd Party の API との https 接続の結果が返ってきていないということが分かりました。

これに関してはプログラム中で、該当するAPIとのhttp通信時に適切なタイムアウトを設定していないことが原因だったため、タイムアウトを設定することで解決しました。

まとめ

なにか問題が起きているが、実際何が起きているのかよく分からない。
そんなときに strace はとても役に立つ可能性があります。
頭の片隅に入れておくといいかも。

uniqueByから始める低計算量アルゴリズムのすゝめ

こんにちは、アプリ開発担当のエモトです。先日、弊社アプリが大型アップデートされました。我々アプリチーム含め社内メンバーと取り組んで、ダークモードなど新しい機能を追加してリリースすることができました。是非、新しくなったアプリをご利用くださいませ。

さて話は変わり、ある配列に対して、その配列の要素が重複しない配列に気軽に変換にしたい。

const array1 = [1, 1, 2, 2, 3, 3]
const array2 = uniqueBy(array1) // [1, 2, 3]

この問題、何も考えずに実装すると計算量 O(N2) となり、非常に大きい計算負荷になってしまいます。安易に実装するぐらいなら、サードライブラリを利用するのが良いと思います。

弊アプリは React Native を採用しているので、Swift などのネイティブ実装と比べると計算量はより気になる要因の1つです。アプリでは lodash の uniqBy を使用していました。ふと気になって、そのソースコード を確認すると while ループが2つ重なるパターンがあり、良い計算量の設計ではないと気づきました。また lodash の代替候補とも言われる justjust-unique は計算量は考慮されているが、重複確認は単純比較のみなので、必ずしも代わりになるわけではないとわかりました。これは何かしないといけない。

Set を利用した手法

重複なしを実現したいなら Set を利用するのが簡単ですが、要素の順番が保証されないケースがほとんどです。しかし、TypeScript (JaveScript) では Set は順序が保証されているとのことで、Set を利用するしかありません。

export const unique = <T>(args: T[]): T[] => [...new Set(args)]

上記だと、要素が Object 型の場合、比較が困難になります。そのため、特定要素を比較する場合も作成しました。

const uniqueBy = <T>(args: T[], key: keyof T): T[] => {
  const valueSet = new Set()
  return args.filter((arg) => {
    const value = arg[key]
    if (valueSet.has(value)) {
      return false
    }
    valueSet.add(value)
    return true
  })
}

検証として 0 から 4 までの数字で構成された 100 万個の要素を持つ配列を用意して、計測しました。

unique uniqueBy
対象配列 [0, 1, 2, ...] [{x: 0}, {x: 1}, {x: 2}, ... ]
計算時間 (msec) 333 21

純粋な Set を利用した unique の方が早いと想像しましたが、予想外にもその unique の方が 10 倍以上の計算時間でした。ソースコードは短いが Set に変換した後に Array に変換するという処理だから?かもしれませんが、詳しくは分かりませんでした。

自作した uniqueBy

検証結果から以下のようなコードを作成しました。

/**
 * 配列から、ユニークな(重複しない)配列を生成する
 *
 * @description
 * keyが未指定の場合、[...new Set(args)] の方が早そうだが、実際は遅かった。
 * なお、jsのSetは順番が保証されている
 */
const _uniqueBy = <T>(args: T[], key?: keyof T): T[] => {
  const valueSet = new Set()
  return args.filter((arg) => {
    const value = key ? arg[key] : arg
    if (valueSet.has(value)) {
      return false
    }
    valueSet.add(value)
    return true
  })
}

/**
 * 単純な配列から、ユニークな(重複しない)配列を生成する
 * - 単純比較できる string[] や number[] など
 */
export const unique = <T>(args: T[]): T[] => _uniqueBy(args)

/**
 * 配列から、その配列内要素の特定keyを基準に、ユニークな(重複しない)配列を生成する
 *
 * @example
 * const uniqueArray = uniqueBy([{x:1}, {x:1}, {x:2}], 'x')
 */
export const uniqueBy = <T>(args: T[], key: keyof T): T[] =>
  _uniqueBy(args, key)

既存ライブラリとの比較

lodash の uniqBy と比較しました。対象データは先ほどと同様な100万個要素の配列を用意しました。

自作/uniqueBy lodash/uniqBy
平均 (msec) 68.9 111.7
標準偏差 (msec) 38.2 13.4
最小 (msec) 24 87
最大 (msec) 141 132

10回ほど検証したところ、多くの場合で、自作の方が早かったです(うれしい)。

まとめ

uniqueBy(重複なし配列への変換)を含め、安易なアルゴリズムでコーディングすると計算量が高くなる処理があります。これらは自作せずに、サードパーティを利用した方が良いと思っています。しかし、それぞれの設計思想や目的があり、自分が使いたいシーンで必ず良い結果や計算量が与えられるとは限らない問題もあります。

今回は対象データや、Set でうまく処理できたことが重なって、自作の採用にメリットがあり挑戦できました。最適なアルゴリズムを考える時間は、とても楽しい開発でした。

最後に、オトバンクではエンジニアを募集中です。日々高速で低計算量なアルゴリズムを考えるのが好きな方、オーディオブック・React Native 開発(Swift や Kotlinのネイティブコードも書いてます)にご興味があれば、是非どうぞ。

お待ちしております。

図でよくわかる Doctrine ORM の基本のキ

こんにちは @kalibora です。

図でよくわかる Doctrine ORM の基本のキ というタイトルで社内LTをしたので、せっかくなので資料を公開しておきます。

EntityManager でよく使うメソッドである persist, flush, clear の挙動を簡単に図解しています。

内容はめっちゃ基本的なものですが、Doctrine 初心者の方には役立つかもしれないのでよろしければどうぞ。