loggerを使って、rollbackの原因を探る


最近また個人開発を始めているんですが、いきなりつまずいたので記録します。
私ごとですが、これからは闇雲デバッグでなく、しっかりロジカルなデバックを心がけていきたいと思います。

思いもよらないところでrollback

rails newし、モデルやコントローラー、ビューのコードを書いて、いざ動かしてみようと思ったら
下のような感じに。。。。。

#ターミナルのサーバ内
Processing by ExampleController#create as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"umwE5o2eXGoMi5vGD5BSPC0JsgkHC49680F+3cgaTxC5zukRZgdqly74jDLxL2tVXvswe0R73cATK90pgShOPg==", "example"=>{"name"=>"example", "place"=>"東京", "introduction"=>"面白い", "movie"=>"example"}, "commit"=>"Create Example"}
   (3.0ms)  begin transaction
   (0.3ms)  rollback transaction
Redirected to http://localhost:5000/example/new

rollbackされてしまいました。。。。
複雑なコードなんか書いていないのに、なぜだろうかと考えていたのですが、全くわからず。。。
調べてみるとloggerで解決できそうなので勉強しました。

ざっくりloggerとは?

loggerというのは、名前の通りでその結果に到るまでのログを吐き出してくれる機能です。
基本的にサーバーの裏で処理されて目に見えないものを、あえて外から見れるようにすることで、
なぜその結果になったのかを追いやすくするものです。今回で言えば、なぜrollbackされたの?ってことですね。

具体的なloggerコード

今回解決策となるloggerコードは、

example_controller.rb
logger.debug インスタンス変数.errors.inspect

#例
@example = Example.create(name :"abc")
logger.debug @example.errors.inspect

注意なのは、いきなりこれが使えるわけではないのと、セット場所もコンソールではなくコントローラーである、ということです。

loggerを使えるようにするための準備

いきなりLoggerは使えるわけではなく、準備が必要です。

config/application.rb
require_relative 'boot'

require 'rails/all'



# Require the gems listed in Gemfile, including any gems
# you've limited to :test, :development, or :production.
Bundler.require(*Rails.groups)

module サービス名
  class Application < Rails::Application
    # Initialize configuration defaults for originally generated Rails version.
    config.load_defaults 5.1
###この1行が必要
    config.logger = Logger.new(STDOUT)
###
    # Settings in config/environments/* take precedence over those specified here.
    # Application configuration should go into files in config/initializers
    # -- all .rb files in that directory are automatically loaded.
  end
end

上記のコードにも書いてあるように、application.rbにconfig.logger = Logger.new(STDOUT)を追記する必要があります。
ちなみにclass Application < Rails::Application〜end内に追記しないと、configというメソッドはないよと怒られるので、しっかりこの中に書きましょう。

configないよっていうエラーの画像です。

上記のコードを追加したら、いよいよloggerが使えます。

具体的なエラー原因探索方法

今回はtransactionにおけるエラーですので、createメソッドでpostした時のエラーです。
ですので、createメソッド内に追記しましょう。

example.controller.rb

  def create
    @example = Example.create(example_params)
    redirect_to action: 'new'
    logger.debug @example.errors.inspect 
  end

注意なのはrails cであるコンソールにはかけないということです。。。
何回もいじって怒られていました。。。。

上の1行を追加し、もう一度createメソッドを起動します。つまり、サービスを操作して適当に何かcreateします。

#ターミナルのサーバ内
Parameters: {"utf8"=>"✓", "authenticity_token"=>"ZK5jDe6KPpFbwSR+wyg4PlO2+L5272x2BDmWdiKMccBnDI76BRMIbHmyM4o9lwFXIER6zDWfPszkUzWCa75w7g==", "example"=>{"name"=>"example", "place"=>"アキバ", "introduction"=>"面白い", "movie"=>""}, "commit"=>"Create Example"}
   (0.1ms)  begin transaction
   (0.1ms)  rollback transaction
Redirected to http://localhost:5000/climbing_movies/new
#<ActiveModel::Errors:0x007fc1a24214c0 @base=#<Example id: nil, created_at: nil, updated_at: nil, name: "example", place: "東京", introduction: "面白い", movie: "", user_id: nil>, @messages={:user=>["must exist"]}, @details={:user=>[{:error=>:blank}]}>

そうすると下にActiveModelに続く、文章が出てきます。
読み方としては、簡単に言いますと、messagesは「こうでなければなりませんよ!」、detailsは「こういう理由でエラーになってますよ」って意味です。

訳してみますと、@message => Userは存在しなければならない、@details => そのはずなのにブランクですよ、だからエラーなんですよと教えてくれています。

userで思い当たる節がmodelしかなく。。。。 user_idとかの参照キーがないのにもかかわらず、リレーションを組んでいました。。。。

リレーションを解消したら無事動きました!

エラー自体はめちゃめちゃ初歩的でしたが、一つエラー解消の勉強ができました。
何かご意見等ありましたらお願いします!

個人開発をされている方へ

Moverというプロダクトを開発しています。登録していただくと、開発したプロダクトのテスト利用を依頼し、フィードバックをもらうことができます。自分のプロダクトを公開して個人開発を加速させましょう!! 現在僕のアカウントも登録されているので、そちらにテスト利用依頼をいただければ実際に使ってみた感想などをお送りさせて頂きます。(アドバイスなどではなく、一人のユーザーとしての感想となります。) もちろん無料です。
https://mover-web.herokuapp.com/