ERROR：【JOB】has been attempted too many times or run too long.

エラー：【JOB】has been attempted too many times or run too long.

他社売価を調べるJobの結果を見ていたところ、奇妙な現象を発見しました。

何故か同じレコードを３つ持っている奴がいる...。

全ての商品でレコードを３つづつ持っているならまだしも、３つ持つものと１つ持つものが存在していました。
ログを確認したところ、タイムアウトエラーが記載されていました。

しかし、このエラーの前に次のようなLOGが。

[2020-01-17 09:06:26] local.INFO: Jobスタート
[2020-01-17 09:06:47] local.INFO: ERROR：4954057104197=>Invalid JAN identifier 4954057104197 for marketplace A1VC38T7YXB528
[2020-01-17 09:06:58] local.INFO: ERROR：4954057105200=>Invalid JAN identifier 4954057105200 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:01] local.INFO: ERROR：4954057105224=>Invalid JAN identifier 4954057105224 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:06] local.INFO: ERROR：4954057105262=>Invalid JAN identifier 4954057105262 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:09] local.INFO: ERROR：4954057105286=>Invalid JAN identifier 4954057105286 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:12] local.INFO: ERROR：4954057105309=>Invalid JAN identifier 4954057105309 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:16] local.INFO: 4954057106160：楽天カタログ登録なし
[2020-01-17 09:07:19] local.INFO: 4954057106191：楽天カタログ登録なし
[2020-01-17 09:07:26] local.INFO: Jobスタート
[2020-01-17 09:07:45] local.INFO: ERROR：4954057104197=>Invalid JAN identifier 4954057104197 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:56] local.INFO: ERROR：4954057105200=>Invalid JAN identifier 4954057105200 for marketplace A1VC38T7YXB528
[2020-01-17 09:07:58] local.INFO: ERROR：4954057105224=>Invalid JAN identifier 4954057105224 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:04] local.INFO: ERROR：4954057105262=>Invalid JAN identifier 4954057105262 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:06] local.INFO: ERROR：4954057105286=>Invalid JAN identifier 4954057105286 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:09] local.INFO: ERROR：4954057105309=>Invalid JAN identifier 4954057105309 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:14] local.INFO: 4954057106160：楽天カタログ登録なし
[2020-01-17 09:08:16] local.INFO: 4954057106191：楽天カタログ登録なし
[2020-01-17 09:08:26] local.INFO: Jobスタート
[2020-01-17 09:08:27] local.INFO: ERROR：4954057111270=>Invalid JAN identifier 4954057111270 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:44] local.INFO: ERROR：4954057104197=>Invalid JAN identifier 4954057104197 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:55] local.INFO: ERROR：4954057105200=>Invalid JAN identifier 4954057105200 for marketplace A1VC38T7YXB528
[2020-01-17 09:08:58] local.INFO: ERROR：4954057105224=>Invalid JAN identifier 4954057105224 for marketplace A1VC38T7YXB528
[2020-01-17 09:09:03] local.INFO: ERROR：4954057105262=>Invalid JAN identifier 4954057105262 for marketplace A1VC38T7YXB528
[2020-01-17 09:09:06] local.INFO: ERROR：4954057105286=>Invalid JAN identifier 4954057105286 for marketplace A1VC38T7YXB528
[2020-01-17 09:09:08] local.INFO: ERROR：4954057105309=>Invalid JAN identifier 4954057105309 for marketplace A1VC38T7YXB528
[2020-01-17 09:09:13] local.INFO: 4954057106160：楽天カタログ登録なし
[2020-01-17 09:09:14] local.INFO: 4934481996070：楽天カタログ登録なし
[2020-01-17 09:09:15] local.INFO: 4954057106191：楽天カタログ登録なし
[2020-01-17 09:09:16] local.INFO: 4934481997633：楽天カタログ登録なし
[2020-01-17 09:09:19] local.INFO: 4934481214792：楽天カタログ登録なし
[2020-01-17 09:09:21] local.INFO: 4934481214815：楽天カタログ登録なし
[2020-01-17 09:09:23] local.INFO: ERROR：4954057111270=>Invalid JAN identifier 4954057111270 for marketplace A1VC38T7YXB528
[2020-01-17 09:09:24] local.INFO: 4934481214808：楽天カタログ登録なし
[2020-01-17 09:09:26] local.INFO: 4934481996117：楽天カタログ登録なし
[2020-01-17 09:09:27] local.ERROR: 【JOB】 has been attempted too many times or run too long. The job may have previously timed out.

ERROR：4954057104197=>Invalid JAN identifier 4954057104197 for marketplace A1VC38T7YXB528

これは日本Amazonに出品が無い事を意味しています。まぁ【ERROR】でアナウンスされていてはダメで回避処理しないといけないのですが、そこは今回おいておいて、レコード重複の原因は３回繰り返されている【JOBスタート】でした。

JOBが３回走った理由

価格調査JOBでは以下の仕掛けをしていました。

#最大試行回数
public $tries = 3;

Job実行に失敗しても３回までは試行してねという奴です。
その為、３回繰り返し４回目にタイムアウトエラーを吐いていました。

となると、実質はタイムアウトエラーではなく別のエラーが問題ということになります。
最初、重い処理だからタイムアウトが発生したのだと思ってましたが、全然理由は違ったわけです。

本当の理由はSQLに存在しないレコードの存在しない値を代入していたからだった

こんな感じのパーツがあったとします。

# 引数
 $itemcode

# 1個目のSQL
 $value = Itemdata::find($itemcode);

# 2個目のSQL
 $value2 = Asincode::where('itemdata_id',$value->id)->first();

今回の原因は１個目のSQLで $value に値が無い事が原因でした。$value=NULLなので$value->idが存在しません。それなのに抽出条件に入れていたためエラーで繰返し処理が発生していました。

う～ん、こうなると「全商品でデータが取れている」と思ってたけど取れてないって事だろうなぁ。

NULLの時の処理を書き加えて解決

１個目と２個目のSQLコードを変更しました。

# 1個目のSQL
 $value = Itemdata::find($itemcode);
 if(!empty($value)){$itemdataID = $value->id;}else{$itemdataID = NULL;}
# 2個目のSQL
 $value2 = Asincode::where('itemdata_id',$itemdataID)->first();

これで無事にエラー回避。

まとめ

テストでは上手くいっても実際のレコードで実行すると上手くいかない事は多々あります。
すぐにバックグラウンド処理に回さないで、一回syncで実行しておけばよかったと少し後悔しつつ、それやるとほかの作業止まるしなぁ～と悩んでる自分がいます。

最も効率的な正解はBackgroundで処理させつつひたすらログを採る事かなぁ。

＼ 最新情報をチェック ／