Laravel5.1+Redisで、メールの送信に失敗する

Question

何か情報お持ちの方いらっしゃいましたら、ご協力いただけますでしょうか。

###調査状況
2/14更新：queueにEloquentのオブジェクトを渡していたところを、例えば
$appointment->toArray();
と、一旦名前付き配列に変換してあげれば、ちゃんと動くことは確認できました。
追記
これでも動いちゃいました。(^-^;
collect($appointment)

2/8更新：Laravelのバージョンを上げ下げして絞り込んだところ、5.1.21まで問題なく、5.1.22以降で問題が発生することが分かりました。

###環境

• Laravel 5.1.45

※5.0からのアップグレード作業中

• Redis

###発生している問題
今までLaravel5.0環境で正しく動作していたシステムを5.1にアップグレードしています。
こちらを参考にして、一通りのソースの修正(5.1.11向けの任意修正以外)を実施しました。
https://readouble.com/laravel/5.1/ja/upgrade.html
修正が終わり動作確認をしていたところ、queueのワーカースレッドにてメール送信の際にエラーが発生してしまうようになりました。
※php artisan queue:listen --tries=3&でジョブ登録済
※詳細は一番下に置きます

[2017-02-01 10:31:41] local.ERROR: exception 'Illuminate\Contracts\Queue\EntityNotFoundException' with message 'Queueable entity [App\Appointment] not found for ID [].'
in /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Database/Eloquent/QueueEntityResolver.php:25

App\Appointmentは独自作成したmodelです。
他にも多数model使用していますが、今のところ、何故かこのmodelでのみエラーが発生します。
not found for ID []なので、レコードを特定するidの値が渡っていないことが分かりますが、not found for ID [14]と言うように、ID値が渡っているのにエラーになることもあります。

###ソースコード
メール送信の処理は、だいぶ省略していますがこんな感じです。

$mail_data_user = [
    'mail_to' => $this->auth->user()->email,
];
\Mail::queue('blade.email.template',
    [
        'user' => $this->auth->user(),
        'appointment' => $appointment,  //App\Appointment
    ],
    function ($message) use ($mail_data_user) {
        $message->subject('メール件名');
        $message->to($mail_data_user['mail_to']);
    });

このソース内において、ddなどで$appointmentの内容を確認すると、キチンと想定通りの内容が格納されています。
###その他

• 処理がメールのbladeまで届いていないことが分かったため、エラーログに出ている各処理の中で受け渡されている値を調べてみたのですが、原因は特定できませんでした…
• 前述のとおり、5.0では正しく動いていました。

5.1にしてからも、App\Appointmentモデルを使用しないメールは、queue経由で送ることができています。

• App\Appointmentモデルは何も特別なことはしていません。

以下、ソースです。

<?php namespace App;

use Illuminate\Database\Eloquent\Model;

class Appointment extends Model {

    protected $table = 'appointments';
    protected $guarded = ['id'];

}

###「failed_jobs」テーブルの内容
内容が業務に関係あるため全文を載せることはできませんが、前半部分だけ参考まで。

{"job":"mailer@handleQueuedMessage","data":{"view":"blade.email.template","data":{"appointment":"::entity::|App\\Appointment|","inputs":{【データ】}},"callback":"C:32:\"SuperClosure\\SerializableClosure\":1638:{a:5:{s:4:\"code\";s:351:\"function ($message) use($appointment) {\n    $message->subject('メール件名');\n    $message->to($mail_data_user['mail_to']);\n};\";s:7:\"context\";a:1:{s:11:\"appointment\";O:15:\"App\\Appointment\":23:{s:8:\"*table\";s:12:\"appointments\";s:10:\"*guarded\";a:1:{i:0;s:2:\"id\";}s:13:\"*connection\";N;s:13:\"*primaryKey\";s:2:\"id\";s:10:\"*perPage\";i:15;s:12:\"incrementing\";b:1;s:10:\"timestamps\";b:1;s:13:\"*attributes\";a:6:…以下略

最初の方に"appointment":"::entity::|App\\Appointment|"とあり、パイプの後が空なのでIDが渡っていないことが分かります。
その後中盤にもApp\\Appointmentがありますが、ここはちょっとよく分かりませんでした。
###出力されたエラー全文

[2017-02-01 10:31:41] local.ERROR: exception 'Illuminate\Contracts\Queue\EntityNotFoundException' with message 'Queueable entity [App\Appointment] not found for ID [].' in /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Database/Eloquent/QueueEntityResolver.php:25
Stack trace:
#0 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(192): Illuminate\Database\Eloquent\QueueEntityResolver->resolve('App\\Appointment', '')
#1 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(174): Illuminate\Queue\Jobs\Job->resolveQueueableEntity('::entity::|App\\...')
#2 [internal function]: Illuminate\Queue\Jobs\Job->Illuminate\Queue\Jobs\{closure}('::entity::|App\\...')
#3 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(175): array_map(Object(Closure), Array)
#4 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(171): Illuminate\Queue\Jobs\Job->resolveQueueableEntities(Array)
#5 [internal function]: Illuminate\Queue\Jobs\Job->Illuminate\Queue\Jobs\{closure}(Array)
#6 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(175): array_map(Object(Closure), Array)
#7 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(129): Illuminate\Queue\Jobs\Job->resolveQueueableEntities(Array)
#8 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Jobs/RedisJob.php(50): Illuminate\Queue\Jobs\Job->resolveAndFire(Array)
#9 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(218): Illuminate\Queue\Jobs\RedisJob->fire()
#10 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(160): Illuminate\Queue\Worker->process('redis', Object(Illuminate\Queue\Jobs\RedisJob), '3', '0')
#11 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(109): Illuminate\Queue\Worker->pop('', 'default', '0', '3', '3')
#12 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Queue/Console/WorkCommand.php(71): Illuminate\Queue\Console\WorkCommand->runWorker('', 'default', '0', '128', false)
#13 [internal function]: Illuminate\Queue\Console\WorkCommand->fire()
#14 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Container/Container.php(507): call_user_func_array(Array, Array)
#15 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Console/Command.php(150): Illuminate\Container\Container->call(Array)
#16 /home/ubuntu/workspace/vendor/symfony/console/Command/Command.php(261): Illuminate\Console\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#17 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Console/Command.php(136): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#18 /home/ubuntu/workspace/vendor/symfony/console/Application.php(843): Illuminate\Console\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#19 /home/ubuntu/workspace/vendor/symfony/console/Application.php(188): Symfony\Component\Console\Application->doRunCommand(Object(Illuminate\Queue\Console\WorkCommand), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#20 /home/ubuntu/workspace/vendor/symfony/console/Application.php(119): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#21 /home/ubuntu/workspace/vendor/laravel/framework/src/Illuminate/Foundation/Console/Kernel.php(107): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#22 /home/ubuntu/workspace/artisan(36): Illuminate\Foundation\Console\Kernel->handle(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#23 {main}  

Answer 1

さらに確認してきました。

queueに登録する際に

$model->getQueueableId();

がコールされて、::entity::|App\Appointment|と連結されるようです。

queueのタイミングで「$model->getQueueableId();」が値を返すか確認できますか。

ソースを確認した感じですと
・getKeyName
・getKey
などがオーバーライドされていると正常に動かなそうです。

https://github.com/illuminate/database/blob/master/Eloquent/Model.php

Comments

[Yu-ki_Satoh]

5.1.21と5.1.22のdiffを確認したところ、`/vendor/laravel/framework/src/Illuminate/Queue/Queue.php`に更新が入っており、ここの挙動を確認しているところです。
この中に`prepareQueueableEntity()`と言うメソッドがあって、ここで `return '::entity::|'.get_class($value).'|'.$value->getQueueableId();`と言う処理があり、`$value->getQueueableId()`が取れていないところまでは確認しました。

> queueのタイミングで「$model->getQueueableId();」が値を返すか確認
してみます！ありがとうございます！

[Yu-ki_Satoh]

とりあえず、上記Queue.phpの以下のメソッド内で確認してみました。
・prepareQueueableEntity()
・prepareQueueableEntities()
「$model->getQueueableId();」が値を返すポイントでは、空文字しか返ってきませんでした。

・getKeyName
・getKey
こちらもworkspace内で使用(override)している箇所は見当たりませんでした…

[3upjp]

後は、saveされていなくてidが未設定、pkがnullで設定されているなどの可能性がありますが
21と12でそこまで差があるのかどうか・・・

> 「$model->getQueueableId();」が値を返すポイントでは、空文字しか返ってきませんでした。

このポイントではattributes内にidは存在しますか？

or いっそのことgetQueueableIdをオーバーライドして　return $this->idにしてしまうとか・・・

[Yu-ki_Satoh]

今、21と22で「prepareQueueableEntity()」メソッド内での変数の値を確認してみました。
21はキチンとmodelがオブジェクト(コレクション)として渡っているのですが、
22はDBから取得した値のみのJSONデータで、model情報が全くありませんでした。

> saveされていなくてidが未設定、pkがnullで設定されているなどの可能性
PKがNULLは無いですね。
saveされていないかどうかは念のため確認してみますが、限りなく可能性は低いと思います…

> 21と12でそこまで差があるのかどうか・・・
21と22の差は微小でした。
https://github.com/laravel/framework/compare/v5.1.21...v5.1.22

> いっそのことgetQueueableIdをオーバーライドして
さ、最後の手段として考えておきます…ｗ

Answer 2

ちょっとしたアイデアなんですが

protected $guarded = ['id'];

これを外したら解決出来ませんか？(gurdedなので関係ないかもしれませんが)

Eloquentのシリアライズ時にidが取得できないのが問題何じゃないかな〜と思いました

Comments

[Yu-ki_Satoh]

ありがとうございます！(涙)
これ試してみましたが、ダメでした…
※もう一件いただいたご回答にもコメントします