【Rails】Railsのログの読み方
はじめに
Railsのログについて、実装の過程で出てきたログをもとに読み方をまとめてみた。
ログの格納場所
Railsは実行環境ごとに異なるログファイルを出力される。
ログの格納場所は、デフォルトでRails.root/log/となっており、ログのファイル名は、アプリケーションが実行されるときの環境が使用される。
＜具体例＞
development環境 → development.log
test環境 → test.log
production環境 → production.oog
ログの内容
正常処理時
基本となるGET、POST、PATCH、DELETE別に解析してみた。
一覧表示【GET】
Started GET "/users" for 127.0.0.1 at 2017-06-06 00:03:08 +0900 Processing by UsersController#index as HTML Rendering users/index.html.erb within layouts/application [1m[36mUser Load (0.2ms)[0m [1m[34mSELECT "users".* FROM "users"[0m Rendered users/index.html.erb within layouts/application (9.2ms) Completed 200 OK in 1069ms (Views: 1050.6ms | ActiveRecord: 1.7ms)
1行目
Started [メソッド] [アクセス先] for [アクセス元IP] at [時間]
→ いつ、どこから、どのメソッドでどんなアクセスがされたか
2行目
Processing by [コントローラ名#メソッド名] as HTML
→ 処理が行われたコントローラとメソッド名と取得した形式
3行目
Rendering [レンダリングされたビューファイル名] within layouts/application
→ レンダリングの内容
4行目
[1m[36mUser Load (0.2ms)[0m [1m[34mSELECT “users”.* FROM “users”[0m
→ [1m[36とか謎の文字列がある。これは、
ANSI shell color codes というものらしく、以下のstackoverflowに情報があった。 stackoverflow.com
上記を取り除くと
mUser Load (0.2ms) SELECT “users”.* FROM “users”
となり、mUserが読み込まれ、ログにあるようなSQLが流れたことを示す。0.2msはかかった時間。
5行目
Rendered users/index.html.erb within layouts/application (9.2ms)
→ layouts/application内でusers/index.html.erbがレンダリングされた。
6行目
Completed 200 OK in 1069ms (Views: 1050.6ms | ActiveRecord: 1.7ms)
→ HTTPステータスコードと処理にかかった時間が表示される。
（ちなみに「200 OK」は、リクエスト成功時に返すレスポンスコード）
データの作成【POST】
Started POST "/users" for 127.0.0.1 at 2017-06-06 06:33:30 +0900
Processing by UsersController#create as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"YyULtXbbHrvd0PtDCocKrWIHSBGfbYJ/xD8V0TyWlWnRiEvFAP0Vu7Aaf/3V9t2FijWXRyLWKiMfbWxIPmjI6A==", "user"=>{"name"=>"aba", "text"=>"a"}, "commit"=>"Create User"}
[1m[35m (0.1ms)[0m [1m[36mbegin transaction[0m
[1m[35mSQL (1.0ms)[0m [1m[32mINSERT INTO "users" ("name", "text", "created_at", "updated_at") VALUES (?, ?, ?, ?)[0m [["name", "aba"], ["text", "a"], ["created_at", "2017-06-05 21:33:30.094146"], ["updated_at", "2017-06-05 21:33:30.094146"]]
[1m[35m (0.9ms)[0m [1m[36mcommit transaction[0m
Redirected to http://0.0.0.0:3000/users/2
Completed 302 Found in 7ms (ActiveRecord: 2.1ms)
（重複したログは省略）
3行目
Parameters: [パラメータの内容]
パラメータの内容。ちなみにパスワードなどはログに書き込まれたくないので、
config/initializers/filter_parameter_logging.rb
Rails.application.config.filter_parameters += [:password]
で、フィルタをかける項目の定義が行える。 なお、フィルタの項目は、ログでは[FILTERED]に置き換えられる。
4行目
begin transaction
→ トランザクションの開始
5行目
実行されたSQL
6行目
commit transaction
→ トランザクションのコミット
7行目
Redirected to [リダイレクト先のURL]
→ 記載のURLにリダイレクトされた
データの更新【PATCH】
Started PATCH "/users/2" for 127.0.0.1 at 2017-06-06 06:33:39 +0900
Processing by UsersController#update as HTML
Parameters: {"utf8"=>"✓", "authenticity_token"=>"c6CWUAYKwBihYJh+GCoOZv1XMgALdnzrA6mC9nqVa1bz1gajw3KZ696HEUg28xh00SIriwfZDIktPesXZymLyA==", "user"=>{"name"=>"abad", "text"=>"ad"}, "commit"=>"Update User", "id"=>"2"}
[1m[36mUser Load (0.2ms)[0m [1m[34mSELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?[0m [["id", 2], ["LIMIT", 1]]
[1m[35m (0.1ms)[0m [1m[36mbegin transaction[0m
[1m[35mSQL (0.6ms)[0m [1m[33mUPDATE "users" SET "name" = ?, "text" = ?, "updated_at" = ? WHERE "users"."id" = ?[0m [["name", "abad"], ["text", "ad"], ["updated_at", "2017-06-05 21:33:39.981554"], ["id", 2]]
[1m[35m (0.9ms)[0m [1m[36mcommit transaction[0m
Redirected to http://0.0.0.0:3000/users/2
Completed 302 Found in 8ms (ActiveRecord: 1.8ms)
目新しいログは無し
データの削除【DELETE】
Started DELETE "/users/1" for 127.0.0.1 at 2017-06-06 06:33:26 +0900
Processing by UsersController#destroy as HTML
Parameters: {"authenticity_token"=>"vMMe9vhpLIjJ+6/krjCuflIVGEJ15gxwEAbQ0FBZiJNchaAIqXiX52Ntps6ZM94rVyg6NLNXxkTBP7ec4qFMRg==", "id"=>"1"}
[1m[36mUser Load (0.3ms)[0m [1m[34mSELECT "users".* FROM "users" WHERE "users"."id" = ? LIMIT ?[0m [["id", 1], ["LIMIT", 1]]
[1m[35m (0.1ms)[0m [1m[36mbegin transaction[0m
[1m[35mSQL (0.6ms)[0m [1m[31mDELETE FROM "users" WHERE "users"."id" = ?[0m [["id", 1]]
[1m[35m (0.9ms)[0m [1m[36mcommit transaction[0m
Redirected to http://0.0.0.0:3000/users
Completed 302 Found in 8ms (ActiveRecord: 2.0ms)
こちらも目新しいログは無し
エラー発生時
Started GET "/users/new" for 127.0.0.1 at 2017-06-06 06:07:05 +0900
Processing by UsersController#new as HTML
Rendering users/new.html.erb within layouts/application
Rendered users/_form.html.haml (6.0ms)
Rendered users/new.html.erb within layouts/application (10.3ms)
Completed 500 Internal Server Error in 44ms (ActiveRecord: 1.8ms)
ActionView::Template::Error (Illegal nesting: nesting within plain text is illegal.):
6:
7: %ul
8: user.errors.full_messages.each do |message|
9: %li = message
10: end
11:
12: %div{ class: "field" }
この時は、ビューでエラーを出してしまった。６行目で「500 Internal Server Error」の記述の後、 具体的な内容がログに出ている。
おまけ
ログファイルをクリアするコマンド
rake log:clear
おわりに
ほんの一例ではあるが、まずはログの場所と大まかな内容の理解ができた。
【メモ】お客様との打合せ時のポイント（時間管理編）
概要
打合せ時の進行ポイントをまとめた。今回は「時間」に関するポイント。
準備、打合せ、打合せ後のポイント
打合せ準備、打合せ後などについては以前の記事参照 sprink.hatenablog.com
心構え
打合せの時間＝「打合せ時間」×「参加人数」
これはよく言われることではあるが、参加人数が多ければ多いほど、トータルの会議時間は増えていく。 １時間で８人出席でも、１日分の時間が消費される。これが１時間伸びて２時間になろうものなら、２日分...そう考えると安易に会議を開催すべきでは無いし、予定時間を過ぎないように（できれば目的を達成しつつ早く終わるように）すべきである。
最大の効果を生む
通常、打合せは予め決められた時間で行われる。前半の議題で時間を使いすぎると、後半の議題に対して十分な時間が確保できず、安易な結論・決定がされがちである。十分な効果を出すために適切に進行する必要がある。
時間管理方法
準備段階でしておくこと
配布するレジュメの題目ごとに時間を書いておく。 また、配布しない場合でも準備段階で時間をメモしておく。当然、時間の妥当性も事前に確認しておく。 時間がシビアな打合せの場合は、レジュメに時間を記載したものを参加者で共有し、打合せ開始時に説明しておくと進めやすい。
予定通り進んでいるか
進行しながら題目ごとの時間を確認する（このペースで時間内で進行できそうかどうか判断していく）。 ひとつの題目で時間がオーバーすると、その後も時間が厳しくなるので題目などの区切りで時間を守るように進行する。 いちいち時計やレジュメを見ると、相手が気になってしまう場合もあるのでレジュメの時間は頭にいれておく（相手に気にしてもらうためにやる場合もあるが）。時間の経過具合もできれば時計を見ずに判断できるとなお良い。
予定通り進んでいない場合
よほどの準備不足でなければ、話がそれることが原因。 それた話を戻す必要がある。
別の課題に発展
→「なるほど、◯◯◯◯◯の課題ですね。検討事項に追加しておきます。今日はあまり時間も無いので、いったん元の課題に話を戻します。」などいったん区切り、かつ検討事項一覧や議事録に課題としてきちんと残して話を戻す。会議に関係の無い話
→雑談的な話はお客様とのコミュニケーションの一環として重要ではある。ただ、時間がない場合は話を戻す必要がある。「では、いったん話を戻しますね。」などと、角が立たないように話を戻す。想定よりも議論が長引く
→想定よりも時間がかかる議題だった場合、課題が大まか過ぎる可能性がある。「細分化→個々に解決」、または「総論的に方向性を出し、各論は別途解決」するなどの対応を行う。単に細分化して解決しそうであれば前者、細分化しても各論同士で、折り合いが付きにくく全体の方向性の取り決めが必要な場合は後者の方法が良い。想定よりも早く終わり過ぎる
→題目のゴールに到達していれば問題が無いが、議論が十分だったか注意する。
予定通り進みやすくする準備
打合せ中の対処だけでなく、なるべくそうならないようにするテクニックとしては、参加者に時間を意識させることである。 具体的には、「題目ごとの時間の提示」だけでなく「なぜ時間通りの進行が必要か」の理由を伝えることがある。
【メモ】お客様との打合せの進め方
概要
システム開発・導入等において、お客様と打合せする際のポイントをまとめた。
準備段階
出席者
出席者、出席者の位置づけ（権限、キーマンかどうか）を確認する。 お客様だけでなく、自分の会社側の出席者についても、役割等打合せで何を期待するかは 事前にすり合わせしておく。役割が無いのであれば、出る必要はない。
必要なもの
会議のレジュメがあると進行しやすいし、後述の会議のイメージもつきやすい。 資料として出す必要がなくても自分用には作るべき。
目的
「打合せすること」が目的になりがちであるが、今一度目的を確認して 「今から準備しようしている打合せの準備は目的を達成できるもの」であるか確認する。
ゴール
目的を達成するために、何がどうなれば良いのか。具体的なゴールを定義しておく。 また、何かを決定する場合はお客様の「誰」に決定権があるのか事前に想定しておく。
例）XXX画面の画面レイアウトを決定する。
XXXの担当者を決定する。
ゴールはレジュメなどに記載し、打合せ時に出席者と認識を合わせると良い。 また、ゴールが「運用フローを決定する」というような大きな場合は、細分化したものを リスト化し、ゴールを小口化すると良い。こうすると全部終われば達成であるし、残っているものは 残課題として今後対処すれば良いものとして明示的になる。
イメージ
準備した資料、出席者をイメージし、頭の中でざっとシミュレーションを行う。 そこで、懸案になりそうなものがあれば事前に回答の準備をしておく。 ここでどれだけイメージし、事前準備できるかが実際の打合せ時のパフォーマンスに大きく影響する。 打合せのパフォーマンスが上がれば、そのプロジェクトに大きくプラスに働く。
打合せ時
時間管理
決まった時間に始める。当たり前のことではあるが、打合せの場所が初めて訪問した場所だと部屋がわからない。 また、お客様とうまく調整できておらず誰を尋ねれば良いかわからないなど、色々とトラブルが起きやすい。 リスクを想定しておき、早めに現地入りするべき。
決まった時間に終わる。打合せは伸びがちであるが、お客様と約束した枠内の時間で終わるように進行すべき。 話が脱線してもすぐ戻したり、検討が長くなりそうであれば、持ち帰りにしてもらう等の工夫が必要。
資料
事前に席に配布し、数に不足がないか確認しておく。
システム画面
できるだけ実際の画面で説明して進める。口頭であれこれしても伝わりにくい。 ”百聞は一見に如かず”である。
最後に決定事項、懸案事項の確認
打合せは、何かを決定する場所なので決定事項は打合せ中に都度確認していくが、 打合せの最後にもおさらいとして全ての決定事項を確認し、認識に誤りがないか漏れが無い確認しておく。 懸案事項についても同様。
次回日時・内容確認／調整
後日でも良いが、可能であればその場に関係者がいるので次回日時も調整しておくと効率的。 次回の内容は、持ち帰りの懸案事項の結果が影響する場合もあるが、こちらもできる限りその場で調整しておいた方が良い。
(トラブルシューティング１)決定したいが、決定権がある人が欠席
「次回に出席してもらおう → また出席しない」というまずいケースになりがち （そもそも出席すべき打合せにでていないので、次回も欠席するケースが多い） 打合せ後にお客様内で確認してもらい、その結果を後日連絡してもらうか次回打合せ時に結果をもらう。
(トラブルシューティング２)決定したいが、そもそも決定する人が決まっていない
誰が決めるか決定してもらう。
→そもそもプロジェクト開始の時点で決まっていた方が良い（お客様含めた体制図）。
当初想定してないものであれば、後日体制図に加筆し関係者で認識を合わせておく。
打合せ後
議事録の作成
- 定型の議事録フォーマットがあればそれで作成し、参加者に送付する。 打合せ時に配布した資料も添付すると良い。 形式張ったものでなくても良いのなら、メール文章内で書いたメモをそのまま送付でも良い。
- 目的は「自分、その他出席者用の備忘録」だけでなく、出席できなかった人への情報共有、 また、言った言わないのトラブルを避けるため。
次回打合せに向けた課題事項への対応
決定事項、懸案事項には速やかに対応する。特に懸案事項について、早期対応の必要が高いものは すぐにやり、問題が小さいうちに対処する。
最後に
打合せをどう進めるのが効率的かどうかは、そのプロジェクトの性質に大きく影響する。 ある程度自分の中でフレームワークを作りつつ、そのプロジェクトに合ったテーラリングして効率化したい。
【schoo】「新人エンジニアが知っておきたいアジャイル開発」を受講した
倉貫さんの２回目の授業で2014年1月27日に公開されている。 受講したので授業の内容や所感をまとめてみた。
授業の概要
「ウェブサービスやアプリの開発に携わる新人エンジニアの方を対象」としているが、アジャイル開発に興味のあるソフトウェアエンジニアにとって非常にわかりやすく、その概要や事例を学べると思った。
また講師の倉貫さんが代表のSonicGardenさんは100%アジャイル開発を行っており、実例や質疑応答での実体験からの回答は非常に参考になった。
なぜ今アジャイル開発なのか
以下のようなポイントが挙げられていた。
- ソフトウェアをインターネット上で直接届けられるようになったことにより、「スピード重視」、「フィードバック」、「スモールスタート」、「スケールアウト」などの特徴を持ち始めたため。
- アジャイル開発の効果としては、「リスクを初期に下げる」、「可視性は常に高く保つ」、「変化コストを一定に保つ」がある。
アジャイルはウォーターフォールなどとの対比で”開発工程”の議論になりがちだけど、結局はアジャイル開発に合う”ビジネスモデル”が前提となる。”ビジネスモデル”に合った手段としてアジャイルが選定されるのであって、作るものが決まりきっているのにアジャイルで開発しても効果が薄いケースが多いのではと思う。 倉貫さんの「いらないものを見つけるために繰り返す」という話も非常に興味深かった。
アジャイル開発の事例に学ぶ
株式会社AsMamaさんの子育てシェアサービスの事例が紹介された。なにを作るのかではなく、なんのために作るのかをしっかり話す。これは、エンジニアのモチベーションだけでなく、別の提案ができないからとのこと。 ”事業の目的を共有する”ことを大切にしているとのことだった。 また具体的な開発、運用の説明もあった。
エンジニアに求められる姿勢
以下のようなポイントが挙げられた。
完成から持続へ
ソフトウェアについて、買った時点で最高品質の「Point of Sales」ではなく、サービス業の使う時点を最高品質にする”Point of Use”があある。”Point of Use”で大切なことは継続性と保守性であり、完成ではなく持続を目指すというのがアジャイル開発で求められる考え方。
当事者意識
”そもそも”から考える癖をつける。解決方法ではなく問題を話しましょうということ。 言われたことを作るだけでは、言われたものを作るだけのエンジニアになってしまう。
保守性を重視する
DRY(Don't Repeat Yourself)。コピペしない。
単位を小さくする
仕事をする単位をいろんな側面で小さくするのが大切。
なるべく作らない
YAGNI(You Aren't Gonna to Need It.)。先に予測して作らない。役に立たない可能性もある。 予測して作って、その予測が当たったら気分が良いが、外れる場合ものあるのでしないほうがよい。
守備範囲を広げる
なるべく分業しないで、自分でできることをたくさん増やしたほうが、効率的でスピード感も出る。 できるだけ兼務していく。
質疑応答
授業の後半では、受講者からの質問があった。気になったものを抜粋。
お客様から意見を引き出すために、工夫していることはありますか？
どういう機能がほしいというのを気軽に話せるようにする。エンジニアから作らない提案をしていくことにより、お客様が思いつきでもどんどん言ってもらえる。アジャイル開発はどういうところから始め、どうやって範囲を広げれば良いか？
”ふりかえり”をしてみて、自分たちのやり方がまずいところがないかコンセンサスを取るのが良いのではないか。いきなりアジャイルを提案しても難しい。
レポート課題
「授業の感想」と「ソフトウェア開発で学びたいテーマ」というレポート課題が出された。
授業を受けてみて思ったこと
「なぜ今アジャイル開発なのか」では、昔ながらの開発とアジャイルの効果が高いWebサービスとの違いがわかりやすく説明されていた。ソフトウェアのもつ特徴が違うため、効果的な開発工程も違ってくるというところがポイントだと感じた。また、単に開発工程ではなくビジネスモデルを含めての理解が必要だと思う。
「アジャイル開発の事例に学ぶ」では、具体例をもとに具体的な開発・運用プロセスを紹介され、アジャイル開発がイメージしやすかった。「エンジニアに求められる姿勢」では、ビジネスモデル、開発・運用プロセスに加えて必要な、エンジニアの心構えが紹介されていた。ここでも、昔ながらの開発との対比もあり違いがわかりやすかった。
【schoo】「どうすれば小さなチームでも大きな成果を出せるのか」を受講した
2013年3月21日に公開されている録画授業だけど、改めて受講したみた。 （schoo無料会員でも一定条件内で録画授業が見れるようです）
はじめに
「小さなチームが大企業に勝つには、機敏であること・同じルールで戦わない」そのためには、開発の無駄を無くすという話から始まった。 これは自分もよく思うところだけど、小さなチームあっても下請けなどで経験してきた大企業のやり方を踏襲するケースも多々あるのではと思う。 小さいチーム（企業）が、大企業と同じやり方で勝てるわけはない。
そもそもソフトウェアの価値とは何か
価値発生のタイミング
ソフトウェアを使って、売り上げを上げたり、コストカットできてから価値が生まれる。ソフトウェアがあるだけでは、価値はない。 ものを作れば、それ自体に価値があるという前提は、問題があると常々感じていたが改めて再認識した。 ここを間違えると、役に立つかどうか考えずに作ることがゴールになってしまいがちだ。
価値は相手によって変わる
「品質」は提供する相手によって品質が変わるという話。
「プログラムの正しさ ＜ 仕様の正しさ ＜ ビジネスの正しさ」という順になる。
ビジネスの正しさをあまり考えずに、仕様を考えると目的が達成できないものが出来上がる。
開発の無駄を無くすための３つのポイントについて
単位を小さくする
SonicGardenさんでは「小口化」と呼んでいるらしい。小口化することで、いろんなことが習慣になるとのこと。 具体的には、コードレビューを１週間単位から１日単位に、１日単位から１時間単位に...小さいサイクルであれば習慣化しやすい。 また、リリースも小さな単位で行うことで、迅速にリリースできるが、単位が大きいとリリースが遅れる。
優先順位を決める
やってはいけないことを素晴らしい効率で行うことほど無駄なことはない ドラッカー
これは本当に共感しかない。目的に向けてやらなければいけないものをリストアップしていくと全てが必要そうで、全てやりたくなるが、 リソースは限られているわけで、一気に全部はできない。 では、優先順位をどうつけていくかが授業で言及されている。 例えば、”そのビジネスで売りたいものはなにか”など、ビジネスを理解することが重要とのこと。 システムを顧客提案するときに、すぐに”便利そうだから”、”あれば良さそうだから”ということに目が行きがちだと思うが、 ビジネスを理解しなければ、何が重要なのか、必要なのかが判断できない。 それと授業でも触れられていたが、優先順位の低いものはそのうちやらなくても良くなることが多いと思う。
なるべく作らない
なるべく作らないことが、保守作業を軽減させる。 「作ること自体に価値はない」という話も出た。 SESだと作ることに対価が払われるため、これに慣れてしまうと作ることに価値を見出してしまいがち、 サービスやパッケージ開発でも同じ思考に陥いるとかなり良くないことが起きる。
また、開発してソースコードを増やしていくと、あたかも資産が増えるように錯覚してしまう。
機能やソースコードは資産ではない。負債である。
ここをしっかり理解し、作るべきことにコストをかけるという考え方だ。
そのためにこれから考えるべきことは
- 自己組織化
- ビジネスモデル
- カルチャー
「仕組み」と「気持ち」の両方を考える必要があるとのこと。
質疑応答
授業の後半では、受講者からの質問があった。
ユーザーストーリーの書き方
「操作をして一周回る」「インプットして最終的にフィードバックが返ってきて完結する」「完成しているかどうか判定しやすいもの」「ユーザーにとって意味がある単位」がポイントとのこと。コードレビューを小口化、習慣化するポイント
リリース前にチェックしているかが重要。SonicGardenさんでは、長いコードは週に一回やっている。成果を出せるカルチャーを作る方法
SonicGardenさんでは、”ふりかえり”によりカルチャーを作っている。
レポート課題
無駄のない開発をするための「そのためにこれから考えるべきこと」について、自分たちのチームで取り組むにはどうすればよいか。というレポート課題が出された。
- 自己組織化
- ビジネスモデル
- カルチャー
授業を受けてみて思ったこと
正直、３年前の授業とは思えず、今日初めて公開された授業だとしてなんも不思議ではない。つまり、非常に本質的な内容なんだと感じた。
この未来のこどもたちへ
娘の幼稚園の運動会、たくさんの子どもたちを見たときに思った。
もし、この中に「プログラマーになりたい！」と、思う子が出てきたとき、その子が大人になったときに、どんな社会が待っているんだろうか。いや、その業種の先輩として、どんな社会を作っておく事が出来るんだろうか。その子が地元で働ける状況になっているのだろうか。
そうなっておらず、首都圏に行くんだろうか。
大企業に就職しても、プログラミングでは無くマネージネント寄りの仕事や雑用的な仕事をすることになって いつの間にか「もの作り」ではない、他のことに追われる日々になっていないだろうか。
一生プログラマーとしてやっていけて、ちゃんと評価される。その中でイキイキと仕事をしている、そんな君たちを見てみたい。
そのためにはビジネスモデルであったり、働き方に変革が必要なことはわかる。
そして今、これから自分が何ができるだろうか。
