tech::hexagram

personal note for technical issue.

初めてOSSにコミットした話

mariaex というElixirのMySQLライブラリにPull Requestを送って、無事に3日前にmergeされた。初めてのOSS貢献で感慨深かったので記事に書いておこうと思う。

github.com

(※@hashijun は会社用のGithubアカウント)

きっかけ

今年の2月頃、業務中にとあるDBのテーブルを設計していて、業務ロジックから生まれる複雑なfieldをどう保存するか悩んでいた。関わっていたのはリリース前のとあるElixir製プロダクト。そのタイミングで保存すべきfieldを絞り込み、テーブルを設計してPull Requestを出した。schemaの中にカラム数は結構あった。

設計したテーブルをレビューしてもらったところ、「それ、まとめてJSONカラム使ったら良いんじゃない?」とベテランの同僚エンジニアから指摘を受けた。確かに、今後カジュアルにカラムを追加したり削除する上で都合が良いので、指摘に沿ってJSONカラムを利用することに。

そのプロダクトではMySQLのライブラリに mariaex を利用していたが、実装当初はJSONカラムがunsupportedだった。

github.com

関連するissueが立っており、repositoryのmaintainerが実装した commit が残っていた(Pull Requestは出ておらず)ため、これを元にmasterからブランチを切って差分を作ってみることに。

試行錯誤を重ねた上でPull Requestを出したが、mergeされるまですんなりとはいかなかった。

github.com

続きを読む

さくらのVPS@Ubuntu14.04でmysqlが起動できなかった

ansibleを利用してmysqlをインストールしていたが、どうもmysqlの起動でコケてしまっていた。 直接ログインして sudo service mysql start を実行してもうんともすんともいわず、困っていた。

mysql.err を見てみると1つWARNINGが出ていたが特に関係のあるものではない。

% sudo tail -n 20 /var/log/mysql.err
171001 22:47:14 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
2017-10-01 22:47:14 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-10-01 22:47:14 0 [Note] /usr/sbin/mysqld (mysqld 5.6.37-log) starting as process 24154 ...
171001 22:47:16 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

my.cnf に下記のオプションを追加したことでWARNINGは解消されたが、依然として起動ができなかった。

explicit_defaults_for_timestamp: 1

困ったなと思って syslog を見てみると気になる内容が。

% sudo tail -n 20 /var/log/syslog
Oct  9 14:34:38 www4184uf kernel: [665121.153306] type=1400 audit(1507527278.123:68): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysql.err" pid=25878 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=105 ouid=105
Oct  9 14:34:38 www4184uf kernel: [665121.153318] type=1400 audit(1507527278.123:69): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysql.err" pid=25878 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=105 ouid=105
Oct  9 14:34:38 www4184uf kernel: [665121.153325] type=1400 audit(1507527278.123:70): apparmor="DENIED" operation="open" profile="/usr/sbin/mysqld" name="/var/log/mysql.err" pid=25878 comm="mysqld" requested_mask="c" denied_mask="c" fsuid=105 ouid=105

apparmorというプロセスに起動を止められている…?WikiPediaによれば、このプロセスはセキュリティを向上させるプログラムとのこと。

AppArmor (Application Armor) とは、Linux Security Modulesの一種であり、各プログラムにセキュリティプロファイルを結びつけ、プログラムのできることに制限をかけるプログラムである。プロファイルは、ネットワークアクセス、Raw socket アクセス、ファイルへの読み書き実行などの機能を制限することができる。

ref. https://ja.wikipedia.org/wiki/AppArmor

とりあえずmysqldに関してapparmorの制限を止める。

sudo ln -s /etc/apparmor.d/usr.sbin.mysqld /etc/apparmor.d/disable/
sudo apparmor_parser -R /etc/apparmor.d/usr.sbin.mysqld

再度mysqlを立ち上げようとすると再び止まってしまっていたので mysql.err を見る。

% sudo tail -n 20 /var/log/mysql.err
/usr/sbin/mysqld: Table 'mysql.plugin' doesn't exist
2017-10-09 15:21:34 15344 [ERROR] Can't open the mysql.plugin table. Please run mysql_upgrade to create it.
2017-10-09 15:21:34 15344 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-10-09 15:21:34 15344 [Note] InnoDB: The InnoDB memory heap is disabled
2017-10-09 15:21:34 15344 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-10-09 15:21:34 15344 [Note] InnoDB: Memory barrier is not used
2017-10-09 15:21:34 15344 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-10-09 15:21:34 15344 [Note] InnoDB: Using Linux native AIO
2017-10-09 15:21:34 15344 [Note] InnoDB: Using CPU crc32 instructions
2017-10-09 15:21:34 15344 [Note] InnoDB: Initializing buffer pool, size = 256.0M
2017-10-09 15:21:34 15344 [Note] InnoDB: Completed initialization of buffer pool
2017-10-09 15:21:34 15344 [Note] InnoDB: Highest supported file format is Barracuda.
2017-10-09 15:21:34 15344 [Note] InnoDB: 128 rollback segment(s) are active.
2017-10-09 15:21:34 15344 [Note] InnoDB: Waiting for purge to start
2017-10-09 15:21:34 15344 [Note] InnoDB: 5.6.37 started; log sequence number 1601046
2017-10-09 15:21:34 15344 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2017-10-09 15:21:34 15344 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
2017-10-09 15:21:34 15344 [Note] Server socket created on IP: '0.0.0.0'.
2017-10-09 15:21:34 15344 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
171009 15:21:34 mysqld_safe mysqld from pid file /var/run/mysqld/mysqld.pid ended

/var/lib/mysql 配下の内容を見てみると、古いplaybookの適用時の残骸が残っていたようで、ファイルの作成日時がばらばらになっていた。

% ls -la /var/lib/mysql
total 143380
drwxr-xr-x  4 mysql mysql     4096 10月  9 15:21 .
drwxr-xr-x 50 root  root      4096 10月  1 22:12 ..
-rw-rw----  1 mysql mysql       56 10月  1 21:37 auto.cnf
-rw-rw----  1 mysql mysql 67108864 10月  9 15:21 ib_logfile0
-rw-rw----  1 mysql mysql 67108864 10月  1 22:47 ib_logfile1
-rw-rw----  1 mysql mysql 12582912 10月  1 23:09 ibdata1
drwx------  2 mysql mysql     4096 10月  1 21:30 mysql
drwx------  2 mysql mysql     4096 10月  1 21:30 test

一旦きれいな状態からインストール作業を試みるためディレクトリごと削除し、mysql-common, mysql-serverのpackageを削除し、再度ansibleを実行してみた。するとmysqlのplaybookは正常に最後まで適用できた。

色々とハマりどころがあったのでなかなか厄介だった。。

MTのテンプレートタグの変数展開

セットした値を mtFor で利用したい場合は、変数名を $ で囲うと展開される。

<mt:SetVar name="current_year" value="2017">
<mt:For var="year" from="1990" to="$current_year" increment="1">
...
</mt:For>

追記: MTテンプレートタグで去年の年を取得する方法として、 MTDate を利用すると良いと一度書いたものの、これは

再構築した日時を表示します。更新日時を表示したいときなどに利用します。

とあるので、「アクセスした日」を起点としての判断ができないらしい。

git fetchで、unable to update local refとエラーが出た場合の対処法

リモートでブランチが削除されたのか、git fetchしようとした時にエラーが出た。 git remote prune origin / git fetch originで解決。

error: there are still refs under 'refs/remotes/origin/XXX`
 ! [new branch]      XXX    -> origin/XXX  (unable to update local ref)
$ git remote prune origin
...

$ git fetch origin
From github.com:xxx/xxx
 * [new branch]      XXX    -> origin/XXX

distilleryを利用したリリースビルドから、command経由でmoduleを実行する際のハマりどころ

2点ハマりどころがあったのでまとめておく。

リリースビルドに含まれないmoduleを実行していないか

/path/to/bin$ ./some command Elixir.Some.Module run ...
{"init terminating in do_boot",{undef,[{'Elixir.Some.Module',application,[],[]},...,{line,24}]},{init,start_em,1,[]},{init,do_boot,3,[]}]}}
init terminating in do_boot ()

/path/to/lib/some 配下で、 Elixir.Some.Module.beam ファイルが生成されているかどうか確認する。

ETSの上限に達していないか

/path/to/bin$ ./some command Elixir.Some.Module run ...
{"init terminating in do_boot",{{badmatch,{error,{some,{{shutdown,{failed_to_start_child,'XXXX',{shutdown,{failed_to_start_child,'XXXX',{system_limit,[{ets,new,['XXXXXX',[set,public,named_table,{read_concurrency,true}]],[]},...{init,start_em,1,[]},{init,do_boot,3,[]}]}}
init terminating in do_boot ()

ETSの上限に達している場合、上記のようなエラーが出る。ETSの上限は ERL_OPTS から "+e 16384" のように渡すことが出来る。

github.com

distilleryのビルドの設定で、 erl_opts から設定を追加する。

github.com

Exqのenqueueのプロセスを追ってみた

仕事に必要だったのでメモ書き程度に残しておく。

Exq というRedisを利用したJob queueライブラリのコードリーディング。

  • Exq.enqueue/4 : use Exq.Enqueuer.EnqueueApi とあるので、その中に実体がある。
# Exq.Enqueuer.EnqueueApi

def enqueue(pid, queue, worker, args), do: enqueue(pid, queue, worker, args, @default_options)

def enqueue(pid, queue, worker, args, options) do
  GenServer.call(pid, {:enqueue, queue, worker, args, options}, Config.get(:genserver_timeout))
end

GenServer の仕組みで :enqueue をメッセージとして送信する。 handle_call:enqueue を処理しているメソッドを探す。

# Exq.Manager.Server

def handle_call({:enqueue, queue, worker, args, options}, from, state) do
  Enqueuer.enqueue(state.enqueuer, from, queue, worker, args, options)
  {:noreply, state, 10}
end
  • Exq.Enqueuer.enqueue: use Exq.Enqueuer.EnqueueApi とあるので、その中に実体がある。
# Exq.Enqueuer.EnqueueApi.enqueue

def enqueue(pid, from, queue, worker, args, options) do
  GenServer.cast(pid, {:enqueue, from, queue, worker, args, options})
end

handle_cast:enqueue を処理しているメソッドを探す。

# Exq.Enqueuer.Server

def handle_cast({:enqueue, from, queue, worker, args, options}, state) do
  response = JobQueue.enqueue(state.redis, state.namespace, queue, worker, args, options)
  GenServer.reply(from, response)
  {:noreply, state}
end
# Exq.Redis.JobQueue
def enqueue(redis, namespace, queue, worker, args, options) do
  {jid, job_serialized} = to_job_serialized(queue, worker, args, options)
  case enqueue(redis, namespace, queue, job_serialized) do
    \:ok    -> {:ok, jid}
    other  -> other
  end
end
def enqueue(redis, namespace, queue, job_serialized) do
  try do
    response = Connection.qp(redis, [
      ["SADD", full_key(namespace, "queues"), queue],
      ["LPUSH", queue_key(namespace, queue), job_serialized]])

    case response do
      {:ok, [%Redix.Error{}, %Redix.Error{}]} = error -> error
      {:ok, [%Redix.Error{}, _]} = error -> error
      {:ok, [_, %Redix.Error{}]} = error -> error
      {:ok, [_, _]} -> \:ok
      other    -> other
    end
  catch
    :exit, e ->
      Logger.info("Error enqueueing -  #{Kernel.inspect e}")
      {:error, :timeout}
  end
end

def to_job_serialized(queue, worker, args, options) do
  to_job_serialized(queue, worker, args, options, Time.unix_seconds)
end
def to_job_serialized(queue, worker, args, options, enqueued_at) do
  jid = UUID.uuid4
  retry = Keyword.get_lazy(options, :max_retries, fn() -> Config.get(:max_retries) end)
  job = %{queue: queue, retry: retry, class: worker, args: args, jid: jid, enqueued_at: enqueued_at}
  {jid, Config.serializer.encode!(job)}
end

というわけで Exq.Redis.JobQueue.enqueue/4 がほぼ実体であることがわかった。Redisに投げているコマンドの詳細は下記となる。


ちなみに dequeue の処理を追うつもりであったが hexdoc に詳細な解説があったので大体の処理の流れは理解できた。

ロードバイクで仙台まで行ってきた

連休を利用し、3泊4日でロードバイクに乗ってはるばる仙台まで自走してきた。

総走破距離は386kmで、これまでで一番遠くまで行くことが出来た。今回の旅に向けて準備してきたこと、旅の道中、旅から帰宅後の反省も含めて記録しておく。このエントリは1万字を超えているので、どんな旅だったかかいつまんでみたい場合は目次を利用していただきたい。

準備編

気をつけたこと

実は去年、同じようにゴールデンウィークを利用して2泊3日でロードバイクに乗って名古屋に行こうとしていた。しかしながら、準備不足で2日目に浜松に到着した時点で体力が底を尽きてしまい、そこから輪行で名古屋に向かったので自走できたのは270kmほどだった。

この経験を踏まえて、今年は下記に気をつけて計画を練った。

1日あたりの走行距離を短縮

去年は1日平均120~130kmの行程で着いたら夕方、しかもヘトヘトで何もする気が起きなかった。自転車旅行で移動がメインの目的ではあるが、日々の目的地に着いた後の観光も(時間は限られてはいるが)楽しみたかったため、1日80km前後を目標に再設定した。

走行中に体に荷物を背負わないようにする

去年リタイアした最大の原因としては、荷物をバックパックに詰めて背負って移動していたため、1日経つ毎に肩の凝りがひどくなったことだった。これを踏まえて、走行時に身につけるものはヒップバッグのみになるようにし、大半の荷物は自転車に積むようにした。

ホテルはコインランドリーがあるところを選ぶ

サイクルウェアは1着しか用意していないので、基本的には宿についたら洗うようにする運用方法を取った。去年は宿に到着後、自分で洗ってたらすごく疲れたので今年はそれを回避。

平地で足を使いすぎない

去年は1日目に静岡の新富士のあたりまで走っていて、行程の終盤に箱根超えがあり、800mほどの登坂をする必要があった。にも関わらず、平地で飛ばしすぎてしまったことで箱根では足が使い物にならずほぼ押して凌いでしまっていた。

県をまたぐ際はほぼ山越えがあると思っていたほうが良いので、それを見据えて平地で気持ちよく走れそうなところもぐっと抑えて足に負担がかからないペースになるように気をつけた。

続きを読む