定期的に `You must provide at least 1 row to be inserted.` が発生している

cumet04 commented 2 weeks ago

sentryにて、タイトル通りのエラー（BQにinsertしようとしているがレコードが与えられていない）が定期的に発生している

cumet04 commented 2 weeks ago

8/13から毎日一定量が観測されている
- 8/13は21件だが、それ以外は24件
エラー一覧を見ると、N時ピッタリ（HH:00:01~HH:00:02あたり）に確実に発生している

cumet04 commented 2 weeks ago

Aug 13, 2024 4:35:01 AM UTC が初出。初出はsttg/prd両方、それ以降はprdのみ5時以降すべて
- JST 8/13 13:35

該当日時近くにリリースは無い。前後は7/27の #105 と8/24の #108 のみ。時間の性質から考えても、raspi側が問題とみてほぼ間違いない

cumet04 commented 2 weeks ago

というかメール通知来ないのが気になる。前に同じ名前の事象をなんらか無視にしてしまっていたか？

-> 以降の記録を #110 へ移動

cumet04 commented 2 weeks ago

こいつを変えてみた（スラッシュ入りからなしにした）けどこれかなチップの内容が今なのか押したあとなのかわからん。。。

cumet04 commented 2 weeks ago

https://docs.sentry.io/product/issues/issue-details/error-issues/#subscribe-to-issue-alerts

To subscribe to an error issue and receive alerts about it, click the bell icon, then fine tune workflow notifications related to the issue in User Settings > Notifications.

だからどっち。

cumet04 commented 2 weeks ago

あと8分もすれば次が来るだろうから様子見。気にせずraspi側を見る

cumet04 commented 2 weeks ago

Aug 25 09:58:02 raspberrypi CRON[323359]: (CRON) info (No MTA installed, discarding output)
Aug 25 09:58:02 raspberrypi CRON[323359]: pam_unix(cron:session): session closed for user root
Aug 25 09:59:01 raspberrypi CRON[323373]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Aug 25 09:59:01 raspberrypi CRON[323374]: (root) CMD (/opt/scanner/record.sh)
Aug 25 09:59:02 raspberrypi CRON[323373]: (CRON) info (No MTA installed, discarding output)
Aug 25 09:59:02 raspberrypi CRON[323373]: pam_unix(cron:session): session closed for user root
Aug 25 10:00:01 raspberrypi CRON[323388]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Aug 25 10:00:01 raspberrypi CRON[323389]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
Aug 25 10:00:01 raspberrypi CRON[323390]: (root) CMD (/opt/scanner/retry.sh)
Aug 25 10:00:01 raspberrypi CRON[323391]: (root) CMD (/opt/scanner/record.sh)
Aug 25 10:00:02 raspberrypi CRON[323388]: (CRON) info (No MTA installed, discarding output)
Aug 25 10:00:02 raspberrypi CRON[323388]: pam_unix(cron:session): session closed for user root
Aug 25 10:00:02 raspberrypi CRON[323389]: (CRON) info (No MTA installed, discarding output)
Aug 25 10:00:02 raspberrypi CRON[323389]: pam_unix(cron:session): session closed for user root
Aug 25 10:01:01 raspberrypi CRON[323414]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)

あリトライっぽいな

cumet04 commented 2 weeks ago

refs #97 #99

リトライを入れたのはここ。7/14とか15とかそのへん。

ただし初回発火の8/13 13:35 JSTに何が起こったのかは謎

cumet04 commented 2 weeks ago

pi@raspberrypi:/opt $ uptime -s
2024-08-13 13:33:55

なるほど

cumet04 commented 2 weeks ago

謎は解けた

8/13 13:34あたりにraspiの再起動が実施される
再起動によりraspiの /opt/scanner/out.json のファイルは中途半端な（レコードが極端に少ない）状態になる
- ここで、記録時間が少なすぎてswitchbotのデバイスのレコードが一つも入ってない
13:35の毎分のrecordが実施されるが、out.jsonにはswitchbotのレコードは一つもないので、エラーになる
- 初出の Aug 13, 2024 4:35:01 AM UTC の分。stgも同じファイルを見てるのでstg/prdともにエラー
- ここで、エラーなのでファイルが削除されず out_20240813_133501.json が残る
14:00以降のリトライにて、ファイルが残っているので毎回リトライが発火するが、最初と同じようにいれるべきレコードが無いのでエラーになる
- エラーなので当然ファイルは削除されず、以下無限ループ

cumet04 commented 2 weeks ago

解としては/record でその可能性を考慮すれば良さそう。

それはそれとして、アラートメールが結局来なくて困るので、その検証のためにエラーを残しておこう

cumet04 commented 2 weeks ago

デフォルトで設定されていたアラートルールが"new issue"に限定されていたからだった

cumet04 commented 2 weeks ago

WHENを "A new issue is created" から "The issue is seen more than 1 times in 15 minutes" としてみた。時間枠15minに対して評価タイミングがいつになるのかは気になるところ。

cumet04 commented 1 week ago

原因になっていた out_20240813_133501.json も削除した

cumet04 / switchbot-logger

定期的に `You must provide at least 1 row to be inserted.` が発生している #109