読者です 読者をやめる 読者になる 読者になる

無職の記録

約3週間ほど無職を体験したのでその記録。

健康保険

3週間ほどであれば、国保の切り替えがベター。 保険証の発行が即行われるので、無職期間中に子供を病院に連れて行っても保険証が提示できるのが大きい。

病院では保険証を提示せず後で精算するみたいなこともできなくはないけど、手続きが恐ろしく面倒ということは以前に学んでいる。

任意継続の場合は、申請書類を郵送して、保険証が帰ってくるというリードタイムが若干あるようだった。 即日性を重視したのであまり調べてないけど、長期的にはメリットが有るのだろう。

年末年始

3週間のうちはじめの1〜2週間は年末年始だったので、あまり無職感を感じなかった。

年賀状作ったり、親戚の家に行ったり、ポケモンしたりしてた。

インフルエンザ

子供がA型インフルエンザと診断を受けて1週間付き添った。「無職でよかった」と思った瞬間である。

幸い症状は軽めだったけど、自分も37.4℃と微熱。喉が痛かったり体がだるかったり寒気がしたりしていたので、多分感染っていた。

おそらく、予防接種が効いて症状が軽くなったのではないかなあと思う。受けててよかった予防接種。

水族館

そんなこんなしていたら無職期間は残り3日となり、かねてから行きたかったすみだ水族館に一人で行ってきた。

年パスも購入したので、また気晴らしに行きたい。

僕はアカクラゲに興味があった。アカクラゲは映画「アカルイミライ」に登場する。アカルイミライについては以前に恥ずかしい感想を書いているように、僕の一番好きな映画だ。

すみだ水族館蜷川実花氏とのコラボでクラゲをフィーチャーしていた。

テカテカと変わる光と音楽によるクラゲのストレスとかを考えてしまっていまいち楽しめなかった。

ほかにも水槽の前でぼーっとしてみたり、だらけきったペンギンなどを見ていた。

一時間ほどウロウロして帰った。

雑談

あまり外に出なかったので、人と話すこと自体が新鮮だった。

僕は普段そんなに喋る方ではないけど、自分でも驚くぐらい人にどうでもいいことを話しかけた。

「雑談なんですけどこの年パスに写っているクラゲって何クラゲですか?」とか、ランチを食べたあとに「ご飯おいしかったです」とか、コンビニの店員さんに「nanacoカードって何ポイントから使えるんですか?」とか、普段なら黙っているような場面で本当にどうでもいい一言を話したりしていた。

コード

そんなに書いてないけど、mrubyにKernel.#callerメソッドがあると便利かなと思って作ってみた。

github.com

まとめ

無職最終日に何をしたらいいかわからず、とりあえずブログを書いてみた。

おしまい。

第三回mruby-spec進捗確認

すでに本人が飽き気味になっていることは世間から全然反応がないからでありウンヌンカンヌン。

Fix bugs

細かいのが多いので一覧はこちらをどうぞ。

https://github.com/mruby/mruby/pulls?utf8=%E2%9C%93&q=is%3Apr%20is%3Aclosed%20author%3Aksss%20created%3A2016-10-01..2017-01-11%20

所感

mruby-specを回してみて無限ループしているっぽい部分をなおした。 (0..Float::INFINITY)みたいなRangeで無限ループしてほしくない場面で無限ループすることが多かった。 無限Range系のバグはほかにもありそうだ。

最近ではshopifyという会社がmrubyを利用しているらしく、沢山のバグ報告がissueに上がっている。 かなり重箱なものが多い印象(NoMethodError = Fixnumした時にsegvするなど)。 しかしながら再現できる小さいコードがついている事が多いのでちまちま潰していくのに向いている。

これらのバグも、修正したときは念のためmruby-specで回したりしている。

他にも数が多くなおしきれていないので、今Hackし放題ですよ。

おきにいりのPR

https://github.com/mruby/mruby/pull/3369

Rubyでの実装とCでの実装で境界が曖昧な感じがmrubyのヨサな気がする。 Cで書くとパフォーマンスが出せるし、Rubyで書くと短く書けるので、メンテしやすくメモリ系のバグも起きにくい。

Unsupported specs

Opalはいかにしてrubyspecをいい感じにアレしているのか - 近&況

こちらの記事のおかげでmspecにdescription指定でskipする機能があることに気がつけました。ありがとうございます。

というわけで、実装してみた。

github.com

現時点ではどうしてもサポートできないfeatureをskipできるようにした。 落ちたspecのdescriptionをtextファイルにコピペするだけ。 これは、昨今のDSL流行に対するアンチテーゼである。

Repro株式会社にJOINする予定です

https://repro.io/を運営するRepro株式会社にJOINする予定です。

Repro

きっかけはCTOのid:joker1007さんでした。

いろいろな道について模索している時に「フリーランスになるとどういう感じなのかなあ」というのを誰かに相談したくても、話せる知り合いはあまりおらず、藁にもすがる思いで以前チョットだけ話したことのあるjoker1007さんに思い切って相談してみたというのが始まりです。

joker1007さんは自分の会社の紹介などは一切せず、親身に相談に乗ってくださいました。

ただ一言「よければうちにも遊びに来て下さい」とのことだったので、一度話を聞いてみると「なんだか面白そうだぞ」となっていきました。

実際は並行していくつかの会社の話を聞いていたのですが、その内いくつかのいいお話をいただいたところから、悩みに悩んで11月末にエイヤでReproに決めた感じです。

実はやりたいことって固定してはあんまりなくて、フワッとエンジニアリング全般を見ていけたらなと思っています。

そしていい感じのOSSを作れる機会を虎視眈々と狙っていきます。

OSS

OSSを作るのがライフワークみたいなところがあるので、Reproでも活動をやめるつもりは全くありません。OSSを書くことは自分への投資だと思っています。

mrubyに関する知見もいくらか*1持っているので、もしそれを活かせる面白い話があれば是非やってみたいと思っておりますので連絡お待ちしております!

予定?

今年の自分のテーマは『余裕』。

ということで、折角の機会なのでリフレッシュ休暇として2週間ほどの空白期間を作ってみました。

とはいえ既に予定が入っていて暇なのは4日間ぐらいですが……。積読を消化したりポケモンをやったりしています。水族館でもいこうかな。

目下の悩みは健康保険問題……。役場で相談してきます。。。

*1:130 commitしているくらいには

2016まとめ

2016何したかなーと思ったのでまとめる。

ちなみに去年の。

ksss9.hatenablog.com

Pull Requests

https://github.com/pulls?utf8=%E2%9C%93&q=is%3Apr+author%3Aksss+is%3Apublic+created%3A2016-01-01..2016-12-31

現時点でOpen: 5, Close: 78

ほとんどがmruby本体とその周辺っぽい。

ちなみにmrubyだけでみると、commit数だけならmatzの次に多い。

Contributors to mruby/mruby · GitHub

Breaking changeはなくて、ひたすらCRubyと仕様を合わせたりバグをなおしたりしていた。

Myself Repositorys

https://github.com/search?q=user%3Aksss+is%3Apublic+created%3A%222016-01-01+..+2016-12-31%22+type%3Apr&ref=searchresults&type=Repositories&utf8=%E2%9C%93

13個。去年より少ないと思う。

json-expect-parserはもうひとひねりあると、いい感じになる気がしないでもない。

active_tsvGitHub.comのgraphs/trafficを見ると意外とcloneされているのがおもしろい。(rubygemsから使ってほしいょ……。)

テキストエディタもはじめて作ってみたのは経験になった。

mruby-specは僕としては役に立った。ruby/specの方との交流もいい経験だった。

Talk

東京Ruby会議11で発表した。

動画を見返すとあまりにカチコチで恥ずかしい……。もっとがんばろう。

「発表をした人」というだけでも知らない方との交流の種になって、いまでも自分の財産になっている。本当にいい経験だった。

Books

読んだ本を数えなくなって、あんまり読まなくなった気がする。

途中まで読んで読みきれないみたいな本がすごく多かった。これは来年の課題としよう。

Privates

家を買った。今年の前半はだいたいこの作業だった気がする。家で仕事をすることは多いし、子供に綺麗で広い家ですごしてもらえる。がんばったかいがあった。

働いていた会社を退職した。今年の後半はこれで結構忙しかった。

子供のことで用事ができることも多く、最後の有休消化期間は2日しか残ってなかった。

総括

2016年はプライベートが大変な年だった。

2017年はもう少しオープンな活動を増やしたい。オープンな活動履歴は、自分の資産になるのだ。

ここ最近の自分のテーマが『余裕』なので、来年のテーマもこれとする。これは、「チームが機能するとはどういうことか」の病院での話が元になっている。手術室を増やすのではなく、緊急用に一つ開けておくとワークする的なやつ。

それでは良いお年を。

最終出社日です

逃げるは恥だが役に立つ

皆さんは逃げ恥観ましたか。

私は5日間で11話全部観ました。TBSオンデマンドで登録すると最初の2週間無料とききつけて登録(したのは妻だけど)。普段からTVは観ない二人なので、始めの2話を観た日は刺激が強すぎるのか二人して寝付けませんでした。 最終話はティーバで無料で観れました。

マンガも8巻まで買って(買ったの妻だけど)読みました。

なんかこう状況が自分たちに被る部分が多かったので大いに感情移入しちゃって「わかるー!」を連発しつつ、二人でみていたわけです。

私は風見さんが好きです。

ああいう風になりたい。「僕は性格が悪いんです」とか言ってみたい。「すいません。」って笑顔で言うの、ズルい。正直で率直かつ相手の気持を気遣える。そこにシビれるあこがれる。

「イケメン」という偏見によって傷ついてきたキャラというのもいい。「イケメン」っていう言葉はもはや褒め言葉ではないしただの偏見・レッテルなんですよね。「イクメン」もそう。私は「イクメン」と呼ばれるのを嫌います。そのうちどちらの言葉も良いイメージはなくなっていって消えていくのではないでしょうか。

閑話休題。作者によると、作品テーマが恋愛と仕事の境目を描くとかそういう感じらしく、うまく現代の夫婦間での問題を表しているなと思います。

この世界の片隅に

映画「この世界の片隅に」も観たんですけど、観るとあの時代はすさまじく女性の扱いが酷いことがわかります。

ひたすら家事をし続ける労働力として見ず知らずの男性の元に嫁ぐ。それが当然とされる時代。*1

そういう時代がたった70年前、私達が住んでいる社会で実際に起こっていて、今も引きずり続けている。

そんな70年前からじわりと社会は成長してきて、色んな人が社会を変えようとがんばってがんばって、ようやく逃げ恥の世界ぐらいまでにはなってきたわけです。*2

二人で自分の家を会社に見立て、共同経営責任者として目標を達成していく。 その目標は「子供をまっとうに育てる」とか「全員の幸福度を最大化する」とかそんな感じなんですけど。

エンゼルバンク

自分自身、この二年と数ヶ月で結婚式をして子供にも恵まれました。

子供も育ち、引っ越し、保育園を探し……。

そうして人生の状況はどんどん変わっていくので、一度システムを見直し、必要に応じて再構築しようと考えました。

「家族にとって自分ができることは何か」

これを考え続け、人生における優先順位を洗い出しました。

何が大切なのか、何が大切でないのか。その優先度にマッチした理想の環境とは何か。

まず3つの選択肢を考えました。

  1. このまま今の会社に残る
  2. 会社員として転職する
  3. フリーランスになる

2.と3.について考えるため、この数ヶ月間色んな人に会いました。

話していくほどに自分の考えがブラッシュアップされていくのを感じました。

そうして考えていく内に、優先順位の変更が発生するわけです。

優先される環境に対する指標として、以下の3つを打ち出しました。

  • 給料
  • リモートワーク
  • 一緒に働く人

給料

シンプルな話、月給の大小です。ある程度の汎用的で認められた能力を持っている自分*3が家族にできる最大限の貢献は、継続的な現金収入であると考えるからです。

個人の給料は、会社のステージ・予算・景気など、様々な要素が絡み合っており、個人の能力だけで決定されるものではありません。 もし私という商品を、もっと高く買ってくれる環境があるなら考慮し選択する。それが家族のためにもなると考えました。

リモートワーク

この2年間で、いかにリモートワークが家族に貢献するかを実感してきました。

これを手放すと、生活環境が大きく変わり、家族にとってマイナスです。

できるだけリモートワークができることを条件として考えました。

いろいろな会社に話を聞いていくと、以下の3パターンの会社に出会いました。

  1. リモートを一切やっていない
  2. 週1〜2くらいでリモートをやっている。それ以上は難しい
  3. 週4〜5リモートでも問題ない

現状は3.です。2.でも許容範囲ですが、他のパラメーターとのバランスも重要です。 極端な話、年収2千万なら1.でもいいわけです。

話を聞いていると、意外と3.は少なく、1.が多い、2.もままある。という印象でした。

いくら他の条件が良くても、この条件によって断念せざるを得ないケースもあり、かなり悩まされました。

一緒に働く人

最初は「仕事の内容がおもしろいか」ぐらいのフワッとした考えだったのですが、 ある人に

「貴方に足りないのは『人』ですよ。」

と言われました。『人』に興味を持って、自分から話しかけたりしているか。それが足りないと。

そうやって考えている内に「重要なのは、仕事内容より人だな」と思うようになりました。(単純か)

そして、とある会社での面談で私が「尊敬できる人と働きたいです」と言うと、「尊敬できる人ってどんな人ですか?」と聞かれました。

そんなこと、これまで考えたことがなかった。それから自分なりに考えました。

私にとって、どんな人が尊敬できるか、どんな人が魅力的か……。そうか、それはOSSを書いている人」だ。

という風に考えがブラッシュアップされていきました。

Reproduction

そんなわけで、これらの条件を満たし、 現実的に最善の選択肢を選び直すことにしました。

地道に、時間をかけて、人に会って、話して、色々な道について考えました。

話を聞きに行って、合わなさそうだなと思ってたら相手側から「合わなさそうですね」的な内容が返ってきたこともありました。

普通に面接して普通に落ちたところもありました。

いい話を頂いて、ギリギリまで悩んだ末選ばなかった道もありました。

そうやっていろんな道を検討した結果、一つの会社に転職することに決めました。(入社エントリも別で書きます。)

spicelifeRubyでの仕事未経験だった私をひろっていただきました。

入社したての頃はRailsも触ったことはなかったし、SQLもJOIN禁止環境で育ったので「has_manyってなんですか?」というレベルでした。

パーフェクトRuby on Railsを買っていただき、端から端までコードを書きつつ読みました。

そうやっていくつかの本を読みました。コードもひたすら書きました。趣味アプリを作ってみたりもしました。

そうやってだましだましやっていく内に、なんとか普通に、いわゆるRailsのお仕事ができるプログラマーとして活躍できるまでになりました。

ここでいったんCMです

f:id:ksss9:20161223214057p:plain

ところでつい最近、私がやってきたサービスのリニューアルがあり、これまで1年ぐらいやってきたものの成果をようやく皆様にお届けすることができました。

TMIXはオリジナルデザインのTシャツやトートバッグなんかを作る事ができるサービスです。

tmix.jp

しかし、肝心要のデザインを作るエディタは、これまでFlashベースの既存システム使っていました。 Flashを触れる人は既におらず、改善したくてもできない……。ブラウザからは近い将来無効化されそう……。バックグラウンドでもFlashに依存しているのでスケールできない……。

そんな状況を打破すべく、Reactベースのエディタに置き換えるという一大事業がありました。

私はそのAPIサーバーのチームリーダー(と言っても全部で2人、内1人は別チームと兼務)として、技術的に課題になる部分を主に担当しました。

これまでより、より綺麗に、より楽しく。

新しくなったTMIXのエディタで、自分のアイコンのトートバックなんか作ったりしてみてはいかがでしょうか。

blog.tmix.jp

Spice up your life

f:id:ksss9:20161223221016j:plain

OSSもいくつか書いて、ほとんどは自己満足で終わりましたが、そのうちいくつかはspicelifeのサービスでも使っていますし、別のOSSプロダクトでも使ってもらったりしています。

RubyKaigi2015でLTしたことや、東京Ruby会議11で話したことなんかは、今でも自己紹介として使えるので非常にいい経験になりました。

spicelifeはRubyでの仕事未経験でも、カンファレンスで発表できるくらいに成長できる環境!!!というのは強調しておきたいと思います。

リモートワークにも大変助けられました。おかげさまで子供も一才半まで成長しました。

働きたい気持ちと能力はあるのだけれど、様々な事情で出社するのはできれば減らしたい……。そんな方は是非spicelifeの門戸を叩いてみてはいかがでしょうか。

spicelifeでは特に、『議論』について学んだ気がします。

その前の会社は下っ端エンジニアをやっていただけなので、わりと言われるがままに実装を進めていましたが、少ない人数で何が最善の道か話し合って答えを出すことの面白さと難しさの両方を学びました

これまでやってきた人たちと、プロダクトの行く末を内側から見れなくなるのはさみしいですが、それは自分で決めたこの変化の代償なのでしょう。

多くのものを学び、もらい、支えていただきました。

本当にありがとうございました。

*1:もちろん拒否できるし、恋愛結婚もあったようだけど

*2:まだ対等とは到底呼べないが

*3:客観視客観視

mruby-spec進捗日記〜第二話〜

ここ最近の出来事をまとめてみた。

ruby/specの作者とPRを交換した

前回のブログを公開した所、ある日メンションがとんできた。

このときは知らなかったけど、CRubyコミッタでruby/specの作者の@eregonさんだった。

僕の英語力は幼稚園児もびっくりの低さなんだけど、そんなことは脇においてハートをぶつけてみた。 僕は英語をGitHubでおぼえたフシがある。 ひたすらmruby-specを作ったときに培った知見を書きなぐってみた。

github.com

ruby/mspecをforkしていたので、この差分もまとめてPRを出した。 mrubyでmspecを動かすための、最小限度の変更。

Support mruby fix #16 by ksss · Pull Request #17 · ruby/mspec · GitHub

このissueでいろいろフィードバックを送ると、あれよあれよとruby/mspecにcommitが積まれていった。 やはりすごい人はアクティブだ。

さらにmruby-spec側にもPRを送ってくれた。

github.com

このアクティブさには圧倒されるばかりだけど、こちらも最低限やりたいことを伝えたりしていろいろやり取りした。

とりあえずハートは伝わったっぽい。ありがとうGoogle翻訳。ありがとうWeblio

そんなこんなでmruby-specは細かい依存がどんどんなくなっていって、ruby/mspecのお作法に乗った作りにパワーアップした。 なにせ作者の助けを借りているのだ。

互いにフィードバックを送り合って高め合う姿勢がすごくよい。これだからOSSは楽しすぎてやめられない。

ライブラリにもフィードバックを送りまくった

https://github.com/iij/mruby-io/pull/65

https://github.com/mattn/mruby-require/pull/31

https://github.com/mattn/mruby-require/pull/32

https://github.com/mattn/mruby-require/pull/34

https://github.com/mattn/mruby-require/pull/35

mruby-specではmattn/mruby-requireをforkしていたので、この差分を還元すべく怒涛のmattn攻めを敢行。 もちろんすべてCRubyと同じ動作になるように配慮している。

Segmentation fault on GC · Issue #44 · mattn/mruby-thread · GitHub

この問題は1週間ぐらい悩んだけど、結局解決にまではいたらなかった。。。 おかげでthreadを使ったときのデバッグ方法や、GCの仕組みに詳しくなれたのでよしとする。

GCについては作者のblogが一番参考になった。

nari.hatenablog.com

mruby本体

https://github.com/mruby/mruby/issues/3214

はちょっとなおし方がわからず難しそう。。。 CRubyがどういうふうになっているのか調べなくちゃなあ。

https://github.com/mruby/mruby/pull/3217

breakのおもしろい挙動を見つけたのでなおしてみた。vm関連はムズカシイ。


もはやmruby-spec関係無い日記

ruby/specにも初PR出した

github.com

mruby-signalをいじっていたらSignal.signameのspecがないのを見つけたのでpatchを書いてみた。

windowsのsignalを試す環境がなくてぐぬってたけど、全環境で使える魔法の数字でなんとかなった。

ruby/rubyにもPR出した

github.com

ruby/specがないけど、じゃあruby/rubyではどうなってるのと思ってドキュメント見てみたら異常ケースが書いてなかったので追加してみた。

るりまはなおってた

github.com

「るりまも直さなきゃなあ」と思っていたらruby/rubyのPRを見たznzさんによって直されていた。 やはりすごい人はアクティブだ。

mruby-specの成果報告

自分の頭の整理のためのエントリーです。 よって超長い。

mruby-spec

以前、mrubyでruby/specを走らせるやつを書いたのですが、 その後どうなったのかまとめてみます。

ksss9.hatenablog.com

成果

  • mruby本体のSEGVを3つなおした。

ruby/specで、まず手を付けていたのはlanguage specでした。 言語の基礎が壊れてたらイカンだろうということで根っこから見ています。

正直言ってまだ走り切ることも困難です。というのもSEGVするから。 SEGVするとそこから先のspecを走らせることができなくなるため、地道に直していました。

https://github.com/mruby/mruby/pull/3204

大体はmac上でデバッグしているのでlldbを使いました。 lldbでlanguage specを走らせてみて、どこで止まったか追ってみます。 mrubyのcommit hashは d58c2585d4d63f13beeb890046ce6c7b514fab91 でした

$ pwd
ksss/mruby-spec

$ lldb mruby/bin/mruby
(lldb) run mspec/bin/mspec-run spec/language
... いっぱいspecが落ちる表示が出る ...
[/ | ========          20%                    | 00:00:00]     19F     51EProcess 3230 stopped
* thread #1: tid = 0x16e74f, 0x000000010006eb9e mruby`get_closure_irep(mrb=0x00000001003002d0, level=0) + 254 at eval.c:31, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x4800000001)
    frame #0: 0x000000010006eb9e mruby`get_closure_irep(mrb=0x00000001003002d0, level=0) + 254 at eval.c:31
   28     if (!e) return NULL;
   29     proc = c->cibase[e->cioff].proc;
   30
-> 31      if (!proc || MRB_PROC_CFUNC_P(proc)) {
   32       return NULL;
   33     }
   34     return proc->body.irep;

うんぜんぜんわからん。ちなみに止まる部分は実行する毎に変わったりします。

Cレベルでのバックトレースを取ってみます。

(lldb) bt
* thread #1: tid = 0x16fbc3, 0x000000010006eb9e mruby`get_closure_irep(mrb=0x0000000100400390, level=0) + 254 at eval.c:31, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x3500000001)
  * frame #0: 0x000000010006eb9e mruby`get_closure_irep(mrb=0x0000000100400390, level=0) + 254 at eval.c:31
    frame #1: 0x000000010006e985 mruby`search_variable(mrb=0x0000000100400390, vsym=326, bnest=0) + 37 at eval.c:44
    frame #2: 0x000000010006e903 mruby`patch_irep(mrb=0x0000000100400390, irep=0x0000000101865dd0, bnest=0) + 723 at eval.c:122
    frame #3: 0x000000010006e595 mruby`create_proc_from_string(mrb=0x0000000100400390, s="x=1", len=3, binding=mrb_value @ 0x00007fff5fbfd1c0, file="(eval)", line=1) + 1205 at eval.c:194
    frame #4: 0x000000010006ddef mruby`f_eval(mrb=0x0000000100400390, self=mrb_value @ 0x00007fff5fbfd398) + 191 at eval.c:215
    frame #5: 0x000000010003ee15 mruby`mrb_vm_exec(mrb=0x0000000100400390, proc=0x000000010202cca0, pc=0x000000010183ab90) + 6613 at vm.c:1150
    frame #6: 0x000000010003d427 mruby`mrb_vm_run(mrb=0x0000000100400390, proc=0x000000010107e670, self=mrb_value @ 0x00007fff5fbfe080, stack_keep=0) + 135 at vm.c:759
    frame #7: 0x00000001000458fb mruby`mrb_top_run(mrb=0x0000000100400390, proc=0x000000010107e670, self=mrb_value @ 0x00007fff5fbfe0f0, stack_keep=0) + 187 at vm.c:2440
    frame #8: 0x000000010006302f mruby`load_exec(mrb=0x0000000100400390, p=0x000000010201d420, c=0x0000000101851ee0) + 1183 at parse.y:5694
    frame #9: 0x0000000100062b73 mruby`mrb_load_file_cxt(mrb=0x0000000100400390, f=0x00007fff79291218, c=0x0000000101851ee0) + 67 at parse.y:5703
    frame #10: 0x0000000100094217 mruby`load_rb_file(mrb=0x0000000100400390, filepath=mrb_value @ 0x00007fff5fbfe410) + 247 at mrb_require.c:425
    frame #11: 0x000000010009305e mruby`load_file(mrb=0x0000000100400390, filepath=mrb_value @ 0x00007fff5fbfe450) + 142 at mrb_require.c:437
    frame #12: 0x0000000100092a13 mruby`mrb_load(mrb=0x0000000100400390, filename=mrb_value @ 0x00007fff5fbfe490) + 51 at mrb_require.c:455
    frame #13: 0x00000001000931d5 mruby`mrb_f_load(mrb=0x0000000100400390, self=mrb_value @ 0x00007fff5fbfe4f0) + 133 at mrb_require.c:470
    frame #14: 0x000000010003ee15 mruby`mrb_vm_exec(mrb=0x0000000100400390, proc=0x000000010107ec40, pc=0x00000001004a0e98) + 6613 at vm.c:1150
    frame #15: 0x000000010003d427 mruby`mrb_vm_run(mrb=0x0000000100400390, proc=0x0000000101047950, self=mrb_value @ 0x00007fff5fbff1d0, stack_keep=0) + 135 at vm.c:759
    frame #16: 0x00000001000458a4 mruby`mrb_top_run(mrb=0x0000000100400390, proc=0x0000000101047950, self=mrb_value @ 0x00007fff5fbff240, stack_keep=0) + 100 at vm.c:2434
    frame #17: 0x000000010006302f mruby`load_exec(mrb=0x0000000100400390, p=0x0000000101019820, c=0x0000000100432020) + 1183 at parse.y:5694
    frame #18: 0x0000000100062b73 mruby`mrb_load_file_cxt(mrb=0x0000000100400390, f=0x00007fff79291050, c=0x0000000100432020) + 67 at parse.y:5703
    frame #19: 0x0000000100001509 mruby`main(argc=3, argv=0x00007fff5fbff668) + 905 at mruby.c:226
    frame #20: 0x00007fff9b92e5ad libdyld.dylib`start + 1
    frame #21: 0x00007fff9b92e5ad libdyld.dylib`start + 1

一見意味不明ですが、よくみるとeval.cでcreate_proc_from_string関数に"x=1"という文字列を渡していることに気が付きます。

$ cd spec && pwd
ksss/mruby-spec/spec

$ git grep x=1 language
language/and_spec.rb:    # evaluates (x=1) and (y=2)
language/ensure_spec.rb:      eval('x=1') # to prevent opts from triggering

どうやらlanguage/ensure_spec.rbがクサいっぽいです。

  it "in no-exception scenarios, is the value of the last statement of the protected body" do
    begin
      v = 1
      eval('x=1') # to prevent opts from triggering
      v
    ensure
      v = 2
    end.should == 1
  end

ありました。eval('x=1')の部分が実に怪しいです。

しかしながら単純にmruby -e 'eval("x=1")'としてもSEGVしません。

再現コードを書こうにも、mspecのコードを読んでできるだけ余計なコードを削除して展開して……。 とやっていると、「ある時点でメソッドを展開するとSEGVが起こらなくなる」という現象に遭遇しました。 最初はサッパリでしたが、途中で「もしやメソッドの呼び出しスタックが深くなるとSEGVが起こりやすくなるのでは?」とひらめき、

1.times{1.times{1.times{1.times{1.times{1.times{1.times{1.times{
1.times{1.times{1.times{1.times{1.times{1.times{1.times{1.times{
  begin
    eval('raise')
  rescue => e
    print e.backtrace
  end
}}}}}}}}
}}}}}}}}

とすることでSEGVを再現できることをたまたま発見できました。

ところがどっこい。 この再現コードはこれまでと全く違う部分でSEGVしているようです。

(lldb) run t.rb
Process 4744 launched: '/Users/yuki/src/github.com/ksss/mruby-spec/mruby/bin/mruby' (x86_64)
Process 4744 stopped
* thread #1: tid = 0x173171, 0x00007fff95b04132 libsystem_c.dylib`strlen + 18, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
    frame #0: 0x00007fff95b04132 libsystem_c.dylib`strlen + 18
libsystem_c.dylib`strlen:
->  0x7fff95b04132 <+18>: pcmpeqb (%rdi), %xmm0
    0x7fff95b04136 <+22>: pmovmskb %xmm0, %esi
    0x7fff95b0413a <+26>: andq   $0xf, %rcx
    0x7fff95b0413e <+30>: orq    $-0x1, %rax
(lldb) up
frame #1: 0x0000000100030d8b mruby`mrb_str_cat_cstr(mrb=0x0000000100600000, str=mrb_value @ 0x00007fff5fbfe380, ptr=0x0000000000000000) + 43 at string.c:2585
   2582 MRB_API mrb_value
   2583 mrb_str_cat_cstr(mrb_state *mrb, mrb_value str, const char *ptr)
   2584 {
-> 2585    return mrb_str_cat(mrb, str, ptr, strlen(ptr));
   2586 }
   2587
   2588 MRB_API mrb_value
(lldb) up
frame #2: 0x000000010000645d mruby`mrb_restore_backtrace(mrb=0x0000000100600000) + 541 at backtrace.c:415
   412          mrb_str_cat(mrb, mrb_entry, &entry->sep, 1);
   413        }
   414
-> 415         mrb_str_cat_cstr(mrb, mrb_entry, mrb_sym2name(mrb, entry->method_id));
   416      }
   417
   418      mrb_ary_push(mrb, backtrace, mrb_entry);
(lldb) up
frame #3: 0x0000000100014eec mruby`exc_get_backtrace(mrb=0x0000000100600000, exc=mrb_value @ 0x00007fff5fbfe510) + 156 at error.c:190
   187    backtrace = mrb_iv_get(mrb, exc, attr_name);
   188    if (mrb_nil_p(backtrace)) {
   189      if (mrb_obj_ptr(exc) == mrb->backtrace.exc && mrb->backtrace.n > 0) {
-> 190         backtrace = mrb_restore_backtrace(mrb);
   191        mrb->backtrace.n = 0;
   192        mrb->backtrace.exc = 0;
   193      }
(lldb) up
frame #4: 0x000000010003ee15 mruby`mrb_vm_exec(mrb=0x0000000100600000, proc=0x000000010081f670, pc=0x000000010064ba58) + 6613 at vm.c:1150
   1147           ci->argc = n;
   1148           ci->nregs = n + 2;
   1149         }
-> 1150          result = m->body.func(mrb, recv);
   1151         mrb_gc_arena_restore(mrb, ai);
   1152         if (mrb->exc) goto L_RAISE;
   1153         /* pop stackpos */

どうやらException#backtraceを呼び出した時にmrb_sym2name(mrb, entry->method_id)NULLを返してしまい、strlen(NULL)のような形になってしまっているようです。entry->method_id23459のような数字でした。これはシンボルのIDのはずなのですが、2万個もシンボルを作っていないはずなので多すぎます。この値が異常っぽいです。それゆえmrb_sym2nameはシンボルIDから文字列に変換するメソッドなのですが、該当するシンボルがないのでNULLを返しているようです。

そもそもmrubyのbacktraceはどうやって取っているのでしょうか? それすら全くわからなかったので、ひたすらコードを読みました。

すると、次のようなことが見えてきました。

  • mrubyのbacktrace情報はmrb->c->ciから取ってきている
  • mrb->cstruct mrb_contextのことで、struct mrb_contextにはcibase, ci, ciendというメンバーがある。
  • cibaseは単に配列で、ciは配列の現在位置、ciendはメモリを確保している最後の印。
  • 最初にcibaseに長さ32個分のメモリを確保、ci = cibaseとして初期化される。
  • mruby側でメソッドを呼び出すたびにciポインタは一つ進み、これまでどういうスタックで呼ばれてきたのかを記録している。
  • ciciendまでくると、mrb_reallocで確保するメモリが2倍に伸長される。

f:id:ksss9:20160909223450p:plain

backtraceはciの位置から一つづつcibaseの位置にもどりつつスタックの情報をbacktrace用に作っていて、肝心要のentry->method_idci->midからコピーしている。

https://github.com/mruby/mruby/blob/501e1ef2605541b98b6f0d2ba2fec69ff068f1cf/src/backtrace.c#L147

当然ci->midは今のスタックのメソッド名(シンボル)でおかしな値はここからコピーされていることがわかった。

さて、ci->midはどこから来るのか。この値はシンボルなので加減算はされないだろう。 さらにあたりをつけると、こんな異常で毎回大きく異る値をとり得るのは、未初期化な場合だろう。

ではciスタックは、どこで作られるんだろう。

実は2箇所しかない。 初期化時と伸長時だ。

https://github.com/mruby/mruby/blob/501e1ef2605541b98b6f0d2ba2fec69ff068f1cf/src/vm.c#L93 https://github.com/mruby/mruby/blob/501e1ef2605541b98b6f0d2ba2fec69ff068f1cf/src/vm.c#L226

バイこのまま細かく書いているといつまでたっても終わらない。どんどん巻いていくと、mrb_callocはじつはmemsetで0初期化する処理が含まれているのでここで異常な値が入るとは考えにくい。 そしてmrb_reallocはその名の通りreallocするので0初期化しない。

さらに、このmrb_realloccibaseを取り直しているcipushはmrubyのevalメソッドからmrb_top_runを通じて呼ばれている。 そしてなんと、このパスではci->midはなにも操作されない。reallocで確保されたメモリではあるが、野ざらしで雑草がぼうぼうに生えた空き地があるだけだ。その雑草が23459。ようやく犯人(草)を掴んだ。

ここで雑草を抜いて綺麗にしておけばなんとかなる。 mrubyの場合、mid=0がCRubyでの<main>を意味するようだ。mrubyではこの場合、単にメソッド名を表示していない。

$ ruby -e 'eval("raise")'
-e:1:in `eval': (eval):1:in `<main>' (RuntimeError)
    from -e:1:in `eval'
    from -e:1:in `<main>'
$ mruby -e 'eval("raise")'
trace:
    [0] (eval):1
    [1] -e:1
(eval):1: RuntimeError

これでようやく一つ倒した。ここまでで一週間以上かかっている。

https://github.com/mruby/mruby/pull/3206

さて、ここまできても最初に見つけたSEGVはなおっていない。つらい。 気を取り直して調べていこう。

lldbで見つけた部分を思い出そう。

   28      if (!e) return NULL;
   29     proc = c->cibase[e->cioff].proc;
   30
-> 31      if (!proc || MRB_PROC_CFUNC_P(proc)) {
   32       return NULL;
   33     }
   34     return proc->body.irep;

ここでいろいろ調べてみると、e->cioff-1であることがわかった。

(lldb) p e->cioff
(ptrdiff_t) $0 = -1

前回、cibaseはスタックの最初であることが分かっていた。cibase[-1]ではあきらかにおかしい。つまりこの時点でe->cioff-1なのがおかしいことになる。

e->cioffとはなにか。そもそもe(REnv*)とはなにか。

REnvで検索していくと、mrb_callinfoRProcという構造体にメンバーとして含まれている。

https://github.com/mruby/mruby/blob/501e1ef2605541b98b6f0d2ba2fec69ff068f1cf/include/mruby/proc.h#L32-L40 https://github.com/mruby/mruby/blob/08a1dd2ac89333bd928a3300f712d1a7fb57e8ff/include/mruby.h#L72-L85

また、REnv型としてメモリ確保されているのはproc.cのenv_new、さらにenv_newclosure_setupが呼んでいる。

https://github.com/mruby/mruby/blob/08a1dd2ac89333bd928a3300f712d1a7fb57e8ff/src/proc.c#L37-L64

closure...クロージャーと言えば、なぜか外側の変数をメソッド内で保持している不思議な奴だった気がするやつだ。 ここで、「struct REnvは外側の環境を保存しておくためのものではないか?」という仮説が浮かび上がる。 ほかにも「環境変数を表すやつか?」とかいろんな仮説が浮かんでは死んでいった。今回もそうだろうか?

proc.hには気になるマクロがある。

https://github.com/mruby/mruby/blob/08a1dd2ac89333bd928a3300f712d1a7fb57e8ff/include/mruby/proc.h#L27-L28

そういえば問題はe->cioff = -1のときなんだった。忘れてた。 これはMRB_ENV_UNSHARE_STACKされた時と見るのが可能性が高そうだ。 多分この数字によってREnvのモードが変わる的な数字だと思う。

cioffの名の通り、おそらくciのoffsetなんだろう。

https://github.com/ksss/mruby/blob/501e1ef2605541b98b6f0d2ba2fec69ff068f1cf/src/proc.c#L45

をみると、cibaseからciがどれぐらい動いているのかを保存している。 おそらくREnvがciスタックにアクセスしたいときに、どのスタックを呼び出せばいいかを保存しているものと見た。

cioff=-1ということはciスタックを参照することはないんだけど、REnvが使われるかもしれないから残しておきたいフラグなのかなあと推測。 MRB_ENV_UNSHARE_STACKが使われるのはcipopされた時だ。自分でも何を言っているのかわからなくなってきた。

vm.cを読むと、cipopcipushという関数がある。cipopというからにはciスタックを元に戻る操作なんだろう。逆にcipushはci スタックを積み上げる操作。

f:id:ksss9:20160910181003p:plain

さらにヒントになったのが、blameしていてみつけたこのPR

github.com

この再現コードでいわゆる"unshare"なREnvを使うことができる。

いろいろいじってみると、たしかに問題のeval.cのあの部分で問題を再現できるのだけど、どうもSEGVにならない。

   28      if (!e) return NULL;
   29     proc = c->cibase[e->cioff].proc;
   30
-> 31      if (!proc || MRB_PROC_CFUNC_P(proc)) {
   32       return NULL;
   33     }
   34     return proc->body.irep;

ここでprocはNULLを指しているからだ。

ここで前回の問題が浮かんだ。"ciスタックが深いと再現するのでは?" そうしてできたのがPRの再現コード。

def m
  Proc.new { eval('raise') }
end

1.times{1.times{1.times{1.times{1.times{1.times{1.times{1.times{
1.times{1.times{1.times{1.times{1.times{1.times{1.times{1.times{
  m.call
}}}}}}}}
}}}}}}}}

ついに来た。これで勝つるというやつだ。

eval.cで問題になっているのは、evalメソッドでRubyコード文字列を引数にして実行した場合に変数も使えるようにしている部分だった。 ここではcioffからciスタックをたどって、その時点の実行コードを読み込もうとしていたが、mメソッド内のciスタックはすでにpopしているのでeはunsharedになっている。これをevalメソッドが引いてきた時にアウトとそういうことっぽい。

つまりはevalメソッド実行時にunshredなREnvが存在すること自体はおかしくないので、もしunshredなら無視するように修正した。

はーこれに二週間かっかったけど勉強になった。

スタックが深くなると起こるバグはほかにもある気がするので、いつかまたハマったら思い出してみよう。

https://github.com/mruby/mruby/pull/3207

これもruby/spec/languageを走らせて遭遇した。

$ lldb mruby/bin/mruby
(lldb) run mspec/bin/mspec-run spec/language/variables_spec.rb
...
* thread #1: tid = 0x1acaab, 0x00000001000023ff mruby`mrb_ary_concat(mrb=0x0000000100202ad0, self=mrb_value @ 0x00007fff5fbfd3a0, other=mrb_value @ 0x00007fff5fbfd390) + 47 at array.c:273, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x28)
    frame #0: 0x00000001000023ff mruby`mrb_ary_concat(mrb=0x0000000100202ad0, self=mrb_value @ 0x00007fff5fbfd3a0, other=mrb_value @ 0x00007fff5fbfd390) + 47 at array.c:273
   270  {
   271    struct RArray *a2 = mrb_ary_ptr(other);
   272
-> 273     ary_concat(mrb, mrb_ary_ptr(self), a2->ptr, a2->len);
   274  }
   275
   276  static mrb_value
(lldb) up
frame #1: 0x00000001000437fa mruby`mrb_vm_exec(mrb=0x0000000100300390, proc=0x00000001008460f0, pc=0x000000010070ccf0) + 25562 at vm.c:2122
   2119
   2120     CASE(OP_ARYCAT) {
   2121       /* A B            mrb_ary_concat(R(A),R(B)) */
-> 2122        mrb_ary_concat(mrb, regs[GETARG_A(i)],
   2123                      mrb_ary_splat(mrb, regs[GETARG_B(i)]));
   2124       ARENA_RESTORE(mrb, ai);
   2125       NEXT;
(lldb) up
frame #2: 0x000000010003d407 mruby`mrb_vm_run(mrb=0x0000000100300390, proc=0x00000001008321d0, self=mrb_value @ 0x00007fff5fbfe070, stack_keep=0) + 135 at vm.c:759
   756    }
   757    stack_extend(mrb, irep->nregs, stack_keep);
   758    mrb->c->stack[0] = self;
-> 759     return mrb_vm_exec(mrb, proc, irep->iseq);
   760  }
   761
   762  MRB_API mrb_value

mrb_ary_concatでの引数othernilになっているので、nilをarrayとして扱おうとして落ちている。再現率100%だ。やった。 OP_ARYCATというvm命令でおきていて、mrb_ary_splatという関数がnilを返しているようだ。

Rubysplatと言えば、*での展開するヤツのことだ。 a = *nil #=> [] a = *'a' #=> ["a"] a = *1 #=> [1] a, b, c = *[1,2,3]; a #=> 1

さて、次の場合はどうなるか。

o = Object.new
a = *o

答えはStringやIntegerと同じく、自身を[]で囲む。

o = Object.new
a = *o
# => [#<Object:0x007fea4315bc08>]

実はこのsplatはto_aメソッドがなければ単に[]で囲んで、to_aがあればそれを呼び出すようになっている。

o = Object.new
def o.to_a
  ['hi']
end
a = *o
#=> ["hi"]

ここから更に細かいが、CRubyでは、to_aメソッドを読んで、nilならto_aメソッドがなかった時と同じく単に[]で囲む。 nilじゃなければArray#concatと同じことをする。くっつけるのは他の変数達。

a = *1, *'', *o
=> [1, "", "hi"]

コードは多分この辺

https://github.com/ruby/ruby/blob/d432af3df7ffa3fb2666674f70dab685e73de374/insns.def#L491-L513

これがmrubyでは実装されておらず、splatは単にto_aの結果を返しているだけだった。

するとto_aメソッドがarray以外を返すと、mrb_ary_concatメソッドでarrayとして処理しようとしてバグとなる。

ここではCRubyと同じ動きになるように、mrb_ary_splatを修正した。

CRubyの挙動にも詳しくなれてmrubyのバグも直って一石二鳥!

このブログ自体も時間をかけて作成されたため、途中で口調が変わっている。

おしまい。