Help us understand the problem. What is going on with this article?

Railsチュートリアル 第12章 パスワードの再設定 - 本番環境での動作に関する演習

1.production環境でユーザー登録を試してみましょう。ユーザー登録時に入力したメールアドレスにメールは届きましたか?

スクリーンショット 2019-12-17 12.38.59.png

まずは「Sign up」画面から、ユーザー登録に必要な情報を入力し、「Create my account」ボタンをクリックします。

スクリーンショット 2019-12-17 12.39.10.png

上記の画面が出て、入力したメールアドレスが有効ならば、実際にメールが到着しているはずです。確認してみましょう。

スクリーンショット 2019-12-17 12.42.29.png

確かにメールが到着していました。

2. メールを受信できたら、実際にメールをクリックしてアカウントを有効化してみましょう。また、Heroku上のログを調べてみて、有効化に関するログがどうなっているのか調べてみてください。

ヒント: ターミナルからheroku logsコマンドを実行してみましょう。

スクリーンショット 2019-12-17 12.47.29.png

まずは、受信したメールの「Activate」リンクをクリックします。

スクリーンショット 2019-12-17 12.48.23.png

無事ユーザーが有効化されました。

ユーザー有効化処理時のサーバーログ

まずはUsersコントローラーのnewアクションに関するログです。新規ユーザー登録情報の入力画面が表示されるところまでです。

2019-12-17T03:38:26.701082+00:00 heroku[router]: at=info method=GET path="/signup" host=warm-woodland-62915.herokuapp.com request_id=9ef43fd8-9976-4b6c-9793-fde8257190ab fwd="103.5.140.188" dyno=web.1 connect=1ms service=28ms status=200 bytes=3428 protocol=https
2019-12-17T03:38:26.675341+00:00 app[web.1]: I, [2019-12-17T03:38:26.675221 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab] Started GET "/signup" for 103.5.140.188 at 2019-12-17 03:38:26 +0000
2019-12-17T03:38:26.676239+00:00 app[web.1]: I, [2019-12-17T03:38:26.676157 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab] Processing by UsersController#new as HTML
2019-12-17T03:38:26.677651+00:00 app[web.1]: I, [2019-12-17T03:38:26.677545 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendering users/new.html.erb within layouts/application
2019-12-17T03:38:26.678404+00:00 app[web.1]: I, [2019-12-17T03:38:26.678315 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered shared/_error_messages.html.erb (0.1ms)
2019-12-17T03:38:26.686611+00:00 app[web.1]: I, [2019-12-17T03:38:26.686532 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered users/_form.html.erb (8.5ms)
2019-12-17T03:38:26.686868+00:00 app[web.1]: I, [2019-12-17T03:38:26.686762 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered users/new.html.erb within layouts/application (9.1ms)
2019-12-17T03:38:26.688192+00:00 app[web.1]: I, [2019-12-17T03:38:26.688122 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered layouts/_rails_default.erb (0.9ms)
2019-12-17T03:38:26.688627+00:00 app[web.1]: I, [2019-12-17T03:38:26.688523 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered layouts/_shim.html.erb (0.1ms)
2019-12-17T03:38:26.689527+00:00 app[web.1]: I, [2019-12-17T03:38:26.689418 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered layouts/_header.html.erb (0.6ms)
2019-12-17T03:38:26.690255+00:00 app[web.1]: I, [2019-12-17T03:38:26.690186 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab]   Rendered layouts/_footer.html.erb (0.3ms)
2019-12-17T03:38:26.690776+00:00 app[web.1]: I, [2019-12-17T03:38:26.690656 #4]  INFO -- : [9ef43fd8-9976-4b6c-9793-fde8257190ab] Completed 200 OK in 14ms (Views: 13.3ms | ActiveRecord: 0.0ms)

続いて、Usersコントローラーのcreateアクションが開始されました。ユーザーの操作としては、「新規ユーザー登録情報の入力画面で、「Submit」ボタンがクリックされたところ」です。

2019-12-17T03:39:00.628200+00:00 app[web.1]: I, [2019-12-17T03:39:00.628068 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Started POST "/signup" for 103.5.140.188 at 2019-12-17 03:39:00 +0000
2019-12-17T03:39:00.629006+00:00 app[web.1]: I, [2019-12-17T03:39:00.628922 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Processing by UsersController#create as HTML
2019-12-17T03:39:00.629110+00:00 app[web.1]: I, [2019-12-17T03:39:00.629041 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"kPI+VonM8nuUu11tRyJNCgkw++6CAdlBZgdH7pgF3GwQjj4/Ah6f7x8yXoXNG4AwTYpDgE+jwtNJ13XXCZMh8w==", "user"=>{"name"=>"Hoge Hoge", "email"=>"[有効なメールアドレス]", "password"=>"[FILTERED]", "password_confirmation"=>"[FILTERED]"}, "commit"=>"Create my account"}
2019-12-17T03:39:00.714970+00:00 app[web.1]: D, [2019-12-17T03:39:00.714832 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]    (1.7ms)  BEGIN
2019-12-17T03:39:00.718390+00:00 app[web.1]: D, [2019-12-17T03:39:00.718293 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   User Exists (2.1ms)  SELECT  1 AS one FROM "users" WHERE LOWER("users"."email") = LOWER($1) LIMIT $2  [["email", "[有効なメールアドレス]"], ["LIMIT", 1]]
2019-12-17T03:39:00.807361+00:00 app[web.1]: D, [2019-12-17T03:39:00.807224 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   SQL (10.7ms)  INSERT INTO "users" ("name", "email", "created_at", "updated_at", "password_digest", "activation_digest") VALUES ($1, $2, $3, $4, $5, $6) RETURNING "id"  [["name", "Hoge Hoge"], ["email", "[有効なメールアドレス]"], ["created_at", "2019-12-17 03:39:00.718914"], ["updated_at", "2019-12-17 03:39:00.718914"], ["password_digest", "$2a$10$tLq83mKKaJN4XGBafxp0BOMpmTDw6iKYj729bNu9dE6jrGYu7w/o6"], ["activation_digest", "$2a$10$CKnDgcIkfShDxkQLli6OU.6vszmQ3rrXdSMa7khjybONYxxNWxNf2"]]
2019-12-17T03:39:00.811145+00:00 app[web.1]: D, [2019-12-17T03:39:00.811013 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]    (3.0ms)  COMMIT

有効化トークンに対応するダイジェストは以下の文字列ですね。

$2a$10$CKnDgcIkfShDxkQLli6OU.6vszmQ3rrXdSMa7khjybONYxxNWxNf2

続いて、メイラーに関するログが返されています。

2019-12-17T03:39:00.817822+00:00 app[web.1]: I, [2019-12-17T03:39:00.817728 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   Rendering user_mailer/account_activation.html.erb within layouts/mailer
2019-12-17T03:39:00.818892+00:00 app[web.1]: I, [2019-12-17T03:39:00.818826 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   Rendered user_mailer/account_activation.html.erb within layouts/mailer (0.9ms)
2019-12-17T03:39:00.819846+00:00 app[web.1]: I, [2019-12-17T03:39:00.819782 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   Rendering user_mailer/account_activation.text.erb within layouts/mailer
2019-12-17T03:39:00.820407+00:00 app[web.1]: I, [2019-12-17T03:39:00.820338 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa]   Rendered user_mailer/account_activation.text.erb within layouts/mailer (0.4ms)
2019-12-17T03:39:01.140739+00:00 app[web.1]: D, [2019-12-17T03:39:01.140608 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] UserMailer#account_activation: processed outbound mail in 328.5ms
2019-12-17T03:39:01.383306+00:00 app[web.1]: I, [2019-12-17T03:39:01.383191 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Sent mail to [有効なメールアドレス] (242.3ms)
2019-12-17T03:39:01.383340+00:00 app[web.1]: D, [2019-12-17T03:39:01.383285 #4] DEBUG -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Date: Tue, 17 Dec 2019 03:39:01 +0000

続いて、ユーザー有効化URL通知用メールのヘッダーが返されます。

2019-12-17T03:39:01.383343+00:00 app[web.1]: From: noreply@example.com
2019-12-17T03:39:01.383345+00:00 app[web.1]: To: [有効なメールアドレス]
2019-12-17T03:39:01.383347+00:00 app[web.1]: Message-ID: <5df84dd5239a7_42b04df0df05c5129@b042e83a-3492-4249-911e-6b41b5e09cd5.mail>
2019-12-17T03:39:01.383349+00:00 app[web.1]: Subject: Account activation
2019-12-17T03:39:01.383351+00:00 app[web.1]: Mime-Version: 1.0
2019-12-17T03:39:01.383353+00:00 app[web.1]: Content-Type: multipart/alternative;
2019-12-17T03:39:01.383355+00:00 app[web.1]: boundary="--==_mimepart_5df84dd521d3b_42b04df0df05c50d3";
2019-12-17T03:39:01.383358+00:00 app[web.1]: charset=UTF-8
2019-12-17T03:39:01.383360+00:00 app[web.1]: Content-Transfer-Encoding: 7bit
2019-12-17T03:39:01.383362+00:00 app[web.1]: 
2019-12-17T03:39:01.383364+00:00 app[web.1]: 
2019-12-17T03:39:01.383366+00:00 app[web.1]: ----==_mimepart_5df84dd521d3b_42b04df0df05c50d3

以下のログには、テキストメールの本文が返されています。

2019-12-17T03:39:01.383368+00:00 app[web.1]: Content-Type: text/plain;
2019-12-17T03:39:01.383370+00:00 app[web.1]: charset=UTF-8
2019-12-17T03:39:01.383372+00:00 app[web.1]: Content-Transfer-Encoding: 7bit
2019-12-17T03:39:01.383374+00:00 app[web.1]: 
2019-12-17T03:39:01.383376+00:00 app[web.1]: Hi Hoge Hoge,
2019-12-17T03:39:01.383377+00:00 app[web.1]: 
2019-12-17T03:39:01.383380+00:00 app[web.1]: Welcome to the Sample App! Click on the link below to activate your account:
2019-12-17T03:39:01.383382+00:00 app[web.1]: 
2019-12-17T03:39:01.383384+00:00 app[web.1]: https://warm-woodland-62915.herokuapp.com/account_activations/iNFYhM1X7rDUmVORFrGMbA/edit?email=[有効なメールアドレス]
2019-12-17T03:39:01.383386+00:00 app[web.1]: 
2019-12-17T03:39:01.383387+00:00 app[web.1]: 
2019-12-17T03:39:01.383390+00:00 app[web.1]: ----==_mimepart_5df84dd521d3b_42b04df0df05c50d3

以下のログには、HTMLメールの本文が返されています。

2019-12-17T03:39:01.383392+00:00 app[web.1]: Content-Type: text/html;
2019-12-17T03:39:01.383393+00:00 app[web.1]: charset=UTF-8
2019-12-17T03:39:01.383395+00:00 app[web.1]: Content-Transfer-Encoding: 7bit
2019-12-17T03:39:01.383397+00:00 app[web.1]: 
2019-12-17T03:39:01.383402+00:00 app[web.1]: <!DOCTYPE html>
2019-12-17T03:39:01.383404+00:00 app[web.1]: <html>
2019-12-17T03:39:01.383406+00:00 app[web.1]: <head>
2019-12-17T03:39:01.383409+00:00 app[web.1]: <meta http-equiv="Content-Type" content="text/html; charset=utf-8" />
2019-12-17T03:39:01.383410+00:00 app[web.1]: <style>
2019-12-17T03:39:01.383412+00:00 app[web.1]: /* Email styles need to be inline */
2019-12-17T03:39:01.383414+00:00 app[web.1]: </style>
2019-12-17T03:39:01.383416+00:00 app[web.1]: </head>
2019-12-17T03:39:01.383418+00:00 app[web.1]: 
2019-12-17T03:39:01.383420+00:00 app[web.1]: <body>
2019-12-17T03:39:01.383422+00:00 app[web.1]: <h1>Sample App</h1>
2019-12-17T03:39:01.383424+00:00 app[web.1]: 
2019-12-17T03:39:01.383426+00:00 app[web.1]: <p>Hi Hoge Hoge,</p>
2019-12-17T03:39:01.383428+00:00 app[web.1]: 
2019-12-17T03:39:01.383430+00:00 app[web.1]: <p>
2019-12-17T03:39:01.383432+00:00 app[web.1]: Welcome to the Sample App! Click on the link below to activate your account:
2019-12-17T03:39:01.383434+00:00 app[web.1]: </p>
2019-12-17T03:39:01.383435+00:00 app[web.1]: 
2019-12-17T03:39:01.383438+00:00 app[web.1]: <a href="https://warm-woodland-62915.herokuapp.com/account_activations/iNFYhM1X7rDUmVORFrGMbA/edit?email=[有効なメールアドレス]">Activate</a>
2019-12-17T03:39:01.383440+00:00 app[web.1]: 
2019-12-17T03:39:01.383441+00:00 app[web.1]: </body>
2019-12-17T03:39:01.383443+00:00 app[web.1]: </html>
2019-12-17T03:39:01.383445+00:00 app[web.1]: 
2019-12-17T03:39:01.383447+00:00 app[web.1]: ----==_mimepart_5df84dd521d3b_42b04df0df05c50d3--

メール本文から、有効化トークンは以下の文字列であることがわかります。

iNFYhM1X7rDUmVORFrGMbA

続いてのログにより、Usersコントローラーのcreateアクションの最後は / へのリダイレクトで完了したことがわかります。

2019-12-17T03:39:01.383918+00:00 app[web.1]: I, [2019-12-17T03:39:01.383828 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Redirected to https://warm-woodland-62915.herokuapp.com/
2019-12-17T03:39:01.384190+00:00 app[web.1]: I, [2019-12-17T03:39:01.384101 #4]  INFO -- : [b0361e09-bbea-4688-bdcd-1f9d317e14fa] Completed 302 Found in 752ms (ActiveRecord: 17.6ms)

今度は、AccountActivationsコントローラーに対するeditが開始されたところからのログです。「メール本文中に記載されたURLにアクセスがあった」というタイミングですね。

2019-12-17T03:48:03.998174+00:00 app[web.1]: I, [2019-12-17T03:48:03.998081 #4]  INFO -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5] Started GET "/account_activations/iNFYhM1X7rDUmVORFrGMbA/edit?email=[有効なメールアドレス]" for 103.5.140.188 at 2019-12-17 03:48:03 +0000
2019-12-17T03:48:03.999604+00:00 app[web.1]: I, [2019-12-17T03:48:03.999504 #4]  INFO -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5] Processing by AccountActivationsController#edit as HTML
2019-12-17T03:48:03.999666+00:00 app[web.1]: I, [2019-12-17T03:48:03.999597 #4]  INFO -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5]   Parameters: {"email"=>"[有効なメールアドレス]", "id"=>"iNFYhM1X7rDUmVORFrGMbA"}
2019-12-17T03:48:04.013441+00:00 app[web.1]: D, [2019-12-17T03:48:04.013350 #4] DEBUG -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5]   User Load (4.0ms)  SELECT  "users".* FROM "users" WHERE "users"."email" = $1 LIMIT $2  [["email", "[有効なメールアドレス]"], ["LIMIT", 1]]
2019-12-17T03:48:04.101912+00:00 app[web.1]: D, [2019-12-17T03:48:04.101770 #4] DEBUG -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5]   SQL (12.9ms)  UPDATE "users" SET "activated" = 't', "activated_at" = '2019-12-17 03:48:04.087544' WHERE "users"."id" = $1  [["id", 104]]
2019-12-17T03:48:04.102898+00:00 app[web.1]: I, [2019-12-17T03:48:04.102788 #4]  INFO -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5] Redirected to https://warm-woodland-62915.herokuapp.com/users/104
2019-12-17T03:48:04.103242+00:00 app[web.1]: I, [2019-12-17T03:48:04.103156 #4]  INFO -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5] Completed 302 Found in 103ms (ActiveRecord: 18.7ms)

(再掲)以下のログのSQL文を見るに、ユーザーの有効化処理は正常に完了したようです。

2019-12-17T03:48:04.101912+00:00 app[web.1]: D, [2019-12-17T03:48:04.101770 #4] DEBUG -- : [f2ca36e3-b2d1-4746-ba15-c67b852fbee5]   SQL (12.9ms)  UPDATE "users" SET "activated" = 't', "activated_at" = '2019-12-17 03:48:04.087544' WHERE "users"."id" = $1  [["id", 104]]

3. アカウントを有効化できたら、今度はパスワードの再設定を試してみましょう。正しくパスワードの再設定ができたでしょうか?

まず、ログインフォームから「forgot password」のリンクをクリックします。

スクリーンショット 2019-12-17 18.38.02.png

パスワード再設定の対象となるユーザーのメールアドレスを入力します。

スクリーンショット 2019-12-17 18.28.09.png

メールが送られてきます。ハイライトした部分は再設定用トークンです。

リンクをクリックして、パスワード再設定フォームへ進みます。

スクリーンショット 2019-12-17 18.28.37.png

新しいパスワードを入力します。

スクリーンショット 2019-12-17 18.29.10.png

パスワードの再設定が完了し、パスワードを再設定したユーザーのプロフィールページが表示されます。

スクリーンショット 2019-12-17 18.29.19.png

パスワード再設定に関するサーバーログ

まずはPasswordResetsコントローラーのnewアクションに関するログです。

2019-12-17T09:27:37.630786+00:00 app[web.1]: I, [2019-12-17T09:27:37.630687 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243] Started GET "/password_resets/new" for 175.177.6.7 at 2019-12-17 09:27:37 +0000
2019-12-17T09:27:37.632157+00:00 app[web.1]: I, [2019-12-17T09:27:37.632064 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243] Processing by PasswordResetsController#new as HTML
2019-12-17T09:27:37.634071+00:00 app[web.1]: I, [2019-12-17T09:27:37.633999 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendering password_resets/new.html.erb within layouts/application
2019-12-17T09:27:37.635383+00:00 app[web.1]: I, [2019-12-17T09:27:37.635314 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendered password_resets/new.html.erb within layouts/application (1.2ms)
2019-12-17T09:27:37.635971+00:00 app[web.1]: I, [2019-12-17T09:27:37.635907 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendered layouts/_rails_default.erb (0.4ms)
2019-12-17T09:27:37.636126+00:00 app[web.1]: I, [2019-12-17T09:27:37.636073 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendered layouts/_shim.html.erb (0.0ms)
2019-12-17T09:27:37.636548+00:00 app[web.1]: I, [2019-12-17T09:27:37.636470 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendered layouts/_header.html.erb (0.2ms)
2019-12-17T09:27:37.636862+00:00 app[web.1]: I, [2019-12-17T09:27:37.636799 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243]   Rendered layouts/_footer.html.erb (0.1ms)
2019-12-17T09:27:37.637075+00:00 app[web.1]: I, [2019-12-17T09:27:37.637018 #4]  INFO -- : [4904fcd9-d965-4f6a-93d7-0fa95587d243] Completed 200 OK in 5ms (Views: 3.7ms | ActiveRecord: 0.0ms)

ここまでのログは、「forgot password」リンクのクリックから、パスワード再設定対象のメールアドレスの入力画面がWebブラウザに表示されるところまでに対応しています。

続いて、PasswordResetsコントローラーのcreateアクションが開始されました。ユーザーの操作としては、「パスワード再設定対象のメールアドレスの入力画面で、「Submit」ボタンがクリックされたところ」です。

2019-12-17T09:28:10.677268+00:00 app[web.1]: I, [2019-12-17T09:28:10.677144 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Started POST "/password_resets" for 175.177.6.7 at 2019-12-17 09:28:10 +0000
2019-12-17T09:28:10.678356+00:00 app[web.1]: I, [2019-12-17T09:28:10.678278 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Processing by PasswordResetsController#create as HTML
2019-12-17T09:28:10.678449+00:00 app[web.1]: I, [2019-12-17T09:28:10.678378 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"s6/JcwQzuM6JAiREt9u1PDuPaKc5we/TAWuJbaIJyxcyV3rusF2/H0ksby8hky03XDCj8W0j/jxFcmxVT61haQ==", "password_reset"=>"[FILTERED]", "commit"=>"Submit"}
2019-12-17T09:28:10.686514+00:00 app[web.1]: D, [2019-12-17T09:28:10.686418 #4] DEBUG -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   User Load (2.8ms)  SELECT  "users".* FROM "users" WHERE "users"."email" = $1 LIMIT $2  [["email", "[有効なメールアドレス]"], ["LIMIT", 1]]
2019-12-17T09:28:10.766666+00:00 app[web.1]: D, [2019-12-17T09:28:10.766571 #4] DEBUG -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   SQL (3.7ms)  UPDATE "users" SET "reset_digest" = '$2a$10$uOXG8lKmc/1ytMzVC5QHAOiY0S/GjmMYHYMb7lVd.dNK8vIsQFYtG', "reset_sent_at" = '2019-12-17 09:28:10.762063' WHERE "users"."id" = $1  [["id", 104]]

(再掲)パスワード再設定トークンに対応するダイジェストをRDBに保存する処理には、以下のログが対応しています。

2019-12-17T09:28:10.766666+00:00 app[web.1]: D, [2019-12-17T09:28:10.766571 #4] DEBUG -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   SQL (3.7ms)  UPDATE "users" SET "reset_digest" = '$2a$10$uOXG8lKmc/1ytMzVC5QHAOiY0S/GjmMYHYMb7lVd.dNK8vIsQFYtG', "reset_sent_at" = '2019-12-17 09:28:10.762063' WHERE "users"."id" = $1  [["id", 104]]

ダイジェストは以下の文字列ですね。

$2a$10$uOXG8lKmc/1ytMzVC5QHAOiY0S/GjmMYHYMb7lVd.dNK8vIsQFYtG

続いて、メイラーに関するログが返されています。

2019-12-17T09:28:10.771901+00:00 app[web.1]: I, [2019-12-17T09:28:10.771829 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   Rendering user_mailer/password_reset.html.erb within layouts/mailer
2019-12-17T09:28:10.772669+00:00 app[web.1]: I, [2019-12-17T09:28:10.772606 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   Rendered user_mailer/password_reset.html.erb within layouts/mailer (0.7ms)
2019-12-17T09:28:10.773513+00:00 app[web.1]: I, [2019-12-17T09:28:10.773447 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   Rendering user_mailer/password_reset.text.erb within layouts/mailer
2019-12-17T09:28:10.773958+00:00 app[web.1]: I, [2019-12-17T09:28:10.773897 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1]   Rendered user_mailer/password_reset.text.erb within layouts/mailer (0.4ms)
2019-12-17T09:28:10.987227+00:00 app[web.1]: D, [2019-12-17T09:28:10.987125 #4] DEBUG -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] UserMailer#password_reset: processed outbound mail in 219.8ms
2019-12-17T09:28:11.369313+00:00 heroku[router]: at=info method=POST path="/password_resets" host=warm-woodland-62915.herokuapp.com request_id=3885b893-52a2-4eed-bc9d-d14c153f57e1 fwd="175.177.6.7" dyno=web.1 connect=1ms service=692ms status=302 bytes=1049 protocol=https
2019-12-17T09:28:11.363917+00:00 app[web.1]: I, [2019-12-17T09:28:11.363795 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Sent mail to [有効なメールアドレス] (376.4ms)
2019-12-17T09:28:11.364042+00:00 app[web.1]: D, [2019-12-17T09:28:11.363974 #4] DEBUG -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Date: Tue, 17 Dec 2019 09:28:10 +0000

続いて、パスワード再設定URL通知用メールのヘッダーが返されます。

2019-12-17T09:28:11.364046+00:00 app[web.1]: From: noreply@example.com
2019-12-17T09:28:11.364048+00:00 app[web.1]: To: [有効なメールアドレス]
2019-12-17T09:28:11.364051+00:00 app[web.1]: Message-ID: <5df89faaf1d68_42b033a8e4c6c36478@0a287fc0-3c85-4948-82ec-158df909485c.mail>
2019-12-17T09:28:11.364053+00:00 app[web.1]: Subject: Password reset
2019-12-17T09:28:11.364055+00:00 app[web.1]: Mime-Version: 1.0
2019-12-17T09:28:11.364057+00:00 app[web.1]: Content-Type: multipart/alternative;
2019-12-17T09:28:11.364059+00:00 app[web.1]: boundary="--==_mimepart_5df89faaf0b60_42b033a8e4c6c36371";
2019-12-17T09:28:11.364062+00:00 app[web.1]: charset=UTF-8
2019-12-17T09:28:11.364064+00:00 app[web.1]: Content-Transfer-Encoding: 7bit

以下のログには、テキストメールの本文が返されています。

2019-12-17T09:28:11.364070+00:00 app[web.1]: ----==_mimepart_5df89faaf0b60_42b033a8e4c6c36371
2019-12-17T09:28:11.364072+00:00 app[web.1]: Content-Type: text/plain;
2019-12-17T09:28:11.364074+00:00 app[web.1]: charset=UTF-8
2019-12-17T09:28:11.364077+00:00 app[web.1]: Content-Transfer-Encoding: 7bit
2019-12-17T09:28:11.364078+00:00 app[web.1]: 
2019-12-17T09:28:11.364081+00:00 app[web.1]: To reset your password click the link below:
2019-12-17T09:28:11.364082+00:00 app[web.1]: 
2019-12-17T09:28:11.364085+00:00 app[web.1]: https://warm-woodland-62915.herokuapp.com/password_resets/itlJPL32OY-XMHORblVHpQ/edit?email=[有効なメールアドレス]
2019-12-17T09:28:11.364087+00:00 app[web.1]: 
2019-12-17T09:28:11.364089+00:00 app[web.1]: This will expire in two hours.
2019-12-17T09:28:11.364091+00:00 app[web.1]: 
2019-12-17T09:28:11.364093+00:00 app[web.1]: If you did not request your password to be reset, please ignore this email and
2019-12-17T09:28:11.364095+00:00 app[web.1]: your password stay as it is.
2019-12-17T09:28:11.364097+00:00 app[web.1]: 
2019-12-17T09:28:11.364099+00:00 app[web.1]: 
2019-12-17T09:28:11.364101+00:00 app[web.1]: ----==_mimepart_5df89faaf0b60_42b033a8e4c6c36371

以下のログには、HTMLメールの本文が返されています。

2019-12-17T09:28:11.364103+00:00 app[web.1]: Content-Type: text/html;
2019-12-17T09:28:11.364105+00:00 app[web.1]: charset=UTF-8
2019-12-17T09:28:11.364107+00:00 app[web.1]: Content-Transfer-Encoding: 7bit
2019-12-17T09:28:11.364109+00:00 app[web.1]: 
2019-12-17T09:28:11.364110+00:00 app[web.1]: <!DOCTYPE html>
2019-12-17T09:28:11.364112+00:00 app[web.1]: <html>
2019-12-17T09:28:11.364115+00:00 app[web.1]: <head>
2019-12-17T09:28:11.364117+00:00 app[web.1]: <meta http-equiv="Content-Type" content="text/html; charset=utf-8" />
2019-12-17T09:28:11.364119+00:00 app[web.1]: <style>
2019-12-17T09:28:11.364121+00:00 app[web.1]: /* Email styles need to be inline */
2019-12-17T09:28:11.364123+00:00 app[web.1]: </style>
2019-12-17T09:28:11.364125+00:00 app[web.1]: </head>
2019-12-17T09:28:11.364128+00:00 app[web.1]: 
2019-12-17T09:28:11.364130+00:00 app[web.1]: <body>
2019-12-17T09:28:11.364132+00:00 app[web.1]: <h1>Password reset</h1>
2019-12-17T09:28:11.364133+00:00 app[web.1]: 
2019-12-17T09:28:11.364135+00:00 app[web.1]: <p>To reset your password click the link below:</p>
2019-12-17T09:28:11.364137+00:00 app[web.1]: 
2019-12-17T09:28:11.364140+00:00 app[web.1]: https://warm-woodland-62915.herokuapp.com/password_resets/itlJPL32OY-XMHORblVHpQ/edit?email=[有効なメールアドレス]
2019-12-17T09:28:11.364141+00:00 app[web.1]: 
2019-12-17T09:28:11.364143+00:00 app[web.1]: <p>This will expire in two hours.</p>
2019-12-17T09:28:11.364145+00:00 app[web.1]: 
2019-12-17T09:28:11.364147+00:00 app[web.1]: <p>
2019-12-17T09:28:11.364150+00:00 app[web.1]: If you did not request your password to be reset, please ignore this email and
2019-12-17T09:28:11.364152+00:00 app[web.1]: your password stay as it is.
2019-12-17T09:28:11.364153+00:00 app[web.1]: </p>
2019-12-17T09:28:11.364155+00:00 app[web.1]: 
2019-12-17T09:28:11.364157+00:00 app[web.1]: </body>
2019-12-17T09:28:11.364159+00:00 app[web.1]: </html>
2019-12-17T09:28:11.364161+00:00 app[web.1]: 
2019-12-17T09:28:11.364164+00:00 app[web.1]: ----==_mimepart_5df89faaf0b60_42b033a8e4c6c36371--

メール本文から、パスワード再設定トークンは以下の文字列であることがわかります。

itlJPL32OY-XMHORblVHpQ

続いてのログにより、PasswordResetsコントローラーのcreateアクションの最後は / へのリダイレクトで完了したことがわかります。

2019-12-17T09:28:11.364629+00:00 app[web.1]: I, [2019-12-17T09:28:11.364565 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Redirected to https://warm-woodland-62915.herokuapp.com/
2019-12-17T09:28:11.364841+00:00 app[web.1]: I, [2019-12-17T09:28:11.364781 #4]  INFO -- : [3885b893-52a2-4eed-bc9d-d14c153f57e1] Completed 302 Found in 686ms (ActiveRecord: 6.5ms)

今度は、PasswordResetsコントローラーに対するeditが開始されたところからのログです。「メール本文中に記載されたURLにアクセスがあった」というタイミングですね。

2019-12-17T09:28:40.413354+00:00 heroku[router]: at=info method=GET path="/password_resets/itlJPL32OY-XMHORblVHpQ/edit?email=[有効なメールアドレス]" host=warm-woodland-62915.herokuapp.com request_id=ed1e4c85-a8ad-4e30-90a9-2d581a582d69 fwd="175.177.6.7" dyno=web.1 connect=1ms service=98ms status=200 bytes=3413 protocol=https
2019-12-17T09:28:40.314045+00:00 app[web.1]: I, [2019-12-17T09:28:40.313937 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69] Started GET "/password_resets/itlJPL32OY-XMHORblVHpQ/edit?email=[有効なメールアドレス]" for 175.177.6.7 at 2019-12-17 09:28:40 +0000
2019-12-17T09:28:40.314979+00:00 app[web.1]: I, [2019-12-17T09:28:40.314889 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69] Processing by PasswordResetsController#edit as HTML
2019-12-17T09:28:40.315025+00:00 app[web.1]: I, [2019-12-17T09:28:40.314972 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Parameters: {"email"=>"[有効なメールアドレス]", "id"=>"itlJPL32OY-XMHORblVHpQ"}
2019-12-17T09:28:40.319097+00:00 app[web.1]: D, [2019-12-17T09:28:40.319022 #4] DEBUG -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   User Load (1.7ms)  SELECT  "users".* FROM "users" WHERE "users"."email" = $1 LIMIT $2  [["email", "[有効なメールアドレス]"], ["LIMIT", 1]]
2019-12-17T09:28:40.398272+00:00 app[web.1]: I, [2019-12-17T09:28:40.398149 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendering password_resets/edit.html.erb within layouts/application
2019-12-17T09:28:40.403019+00:00 app[web.1]: I, [2019-12-17T09:28:40.402925 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered shared/_error_messages.html.erb (0.7ms)
2019-12-17T09:28:40.405414+00:00 app[web.1]: I, [2019-12-17T09:28:40.405331 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered password_resets/edit.html.erb within layouts/application (7.0ms)
2019-12-17T09:28:40.406458+00:00 app[web.1]: I, [2019-12-17T09:28:40.406378 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered layouts/_rails_default.erb (0.7ms)
2019-12-17T09:28:40.406920+00:00 app[web.1]: I, [2019-12-17T09:28:40.406841 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered layouts/_shim.html.erb (0.0ms)
2019-12-17T09:28:40.407613+00:00 app[web.1]: I, [2019-12-17T09:28:40.407535 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered layouts/_header.html.erb (0.4ms)
2019-12-17T09:28:40.408136+00:00 app[web.1]: I, [2019-12-17T09:28:40.408058 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69]   Rendered layouts/_footer.html.erb (0.2ms)
2019-12-17T09:28:40.408613+00:00 app[web.1]: I, [2019-12-17T09:28:40.408534 #4]  INFO -- : [ed1e4c85-a8ad-4e30-90a9-2d581a582d69] Completed 200 OK in 93ms (Views: 10.7ms | ActiveRecord: 1.7ms)

ここまでのログは、パスワード再設定画面がWebブラウザに表示されるところまでに対応しています。

続いて、PasswordResetsコントローラーのupdateアクションが開始されました。ユーザーの操作としては、「パスワード再設定画面で、「Submit」ボタンがクリックされたところ」です。

2019-12-17T09:29:12.595676+00:00 app[web.1]: I, [2019-12-17T09:29:12.595538 #4]  INFO -- : [8848c122-5082-4846-86ce-2ceb8b852cbe] Started PATCH "/password_resets/itlJPL32OY-XMHORblVHpQ" for 175.177.6.7 at 2019-12-17 09:29:12 +0000
2019-12-17T09:29:12.596922+00:00 app[web.1]: I, [2019-12-17T09:29:12.596829 #4]  INFO -- : [8848c122-5082-4846-86ce-2ceb8b852cbe] Processing by PasswordResetsController#update as HTML
2019-12-17T09:29:12.597042+00:00 app[web.1]: I, [2019-12-17T09:29:12.596951 #4]  INFO -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]   Parameters: {"utf8"=>"✓", "authenticity_token"=>"dg4e+oRJwi5xsE/Jz4Pmq+2UoA2OiDh5+ocmuTpFoVb2ch6TD5uvuvo5TCFFuiuRqS4YY0MqI+vVVxSAq9NcyQ==", "email"=>"[有効なメールアドレス]]", "user"=>{"password"=>"[FILTERED]", "password_confirmation"=>"[FILTERED]"}, "commit"=>"Update password", "id"=>"itlJPL32OY-XMHORblVHpQ"}
2019-12-17T09:29:12.601036+00:00 app[web.1]: D, [2019-12-17T09:29:12.600952 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]   User Load (1.6ms)  SELECT  "users".* FROM "users" WHERE "users"."email" = $1 LIMIT $2  [["email", "[有効なメールアドレス]"], ["LIMIT", 1]]
2019-12-17T09:29:12.677061+00:00 app[web.1]: D, [2019-12-17T09:29:12.676951 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]    (1.4ms)  BEGIN
2019-12-17T09:29:12.756980+00:00 app[web.1]: D, [2019-12-17T09:29:12.756856 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]   User Exists (1.6ms)  SELECT  1 AS one FROM "users" WHERE LOWER("users"."email") = LOWER($1) AND ("users"."id" != $2) LIMIT $3  [["email", "[有効なメールアドレス]"], ["id", 104], ["LIMIT", 1]]
2019-12-17T09:29:12.759699+00:00 app[web.1]: D, [2019-12-17T09:29:12.759627 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]   SQL (1.4ms)  UPDATE "users" SET "password_digest" = $1, "updated_at" = $2 WHERE "users"."id" = $3  [["password_digest", "$2a$10$H0x3ghcOyu0l4DHat9NqLOsJ0.xRYZ.DDKTXvoaO18Ot7E5p/omzq"], ["updated_at", "2019-12-17 09:29:12.757425"], ["id", 104]]
2019-12-17T09:29:12.762463+00:00 app[web.1]: D, [2019-12-17T09:29:12.762374 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]    (2.4ms)  COMMIT
2019-12-17T09:29:12.763828+00:00 app[web.1]: D, [2019-12-17T09:29:12.763760 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]    (1.1ms)  BEGIN
2019-12-17T09:29:12.765871+00:00 app[web.1]: D, [2019-12-17T09:29:12.765779 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]   SQL (1.3ms)  UPDATE "users" SET "reset_digest" = $1, "updated_at" = $2 WHERE "users"."id" = $3  [["reset_digest", nil], ["updated_at", "2019-12-17 09:29:12.763908"], ["id", 104]]
2019-12-17T09:29:12.768224+00:00 app[web.1]: D, [2019-12-17T09:29:12.768124 #4] DEBUG -- : [8848c122-5082-4846-86ce-2ceb8b852cbe]    (2.1ms)  COMMIT
2019-12-17T09:29:12.768664+00:00 app[web.1]: I, [2019-12-17T09:29:12.768603 #4]  INFO -- : [8848c122-5082-4846-86ce-2ceb8b852cbe] Redirected to https://warm-woodland-62915.herokuapp.com/users/104
2019-12-17T09:29:12.768800+00:00 app[web.1]: I, [2019-12-17T09:29:12.768749 #4]  INFO -- : [8848c122-5082-4846-86ce-2ceb8b852cbe] Completed 302 Found in 172ms (ActiveRecord: 15.9ms)

パスワードの再設定が正常に完了していますね。最後は当該ユーザーのプロフィールページにリダイレクトされています。

rapidliner00
* 現在のところは、エンジニアに憧れる非エンジニア * エンジニア的な業務効率化・改善に興味あり
Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
No comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
ユーザーは見つかりませんでした