Error in log when running 0.7.0
Closed this issue · 4 comments
Hi,
Running 0.7.0. I've been noticing some errors showing up in the log. I haven't been able to trigger this, so I don't have a way to reproduce it.
Jul 22 12:56:01.469 ERRO Error leaked out the bottom: Error("invalid value: integer -1, expected usize", line: 1, column: 492)
I've noticed that the column value changes. I've seen 447, 492, 493, 494, 518
Things are running very well otherwise. Just sharing - don't think this is super urgent.
Mark
I think this is a serde error when attempting to deserialize a usize with a -1 value. I was able to recreate this by manually enqueueing a job with a retry_count of -1.
I found the error: Jul 22 13:57:27.475 ERRO Error leaked out the bottom: Error("invalid value: integer -1, expected usize", line: 1, column: 208)
And that would make sense why the column keeps changing because it's referring to the position of the json payload.
I don't think it's possible for this lib to push a -1 as retry count because we use usize for everything and rust would likely panic before we made it to redis. It might be possible for sidekiq.rb to enqueue a -1 but unlikely? It also might not be the retry count field causing issues.
Btw, if you move up the stack and create a worker with usize but force an isize value into redis, it will retry the error as expected: Jul 22 14:06:44.817 ERRO Scheduling job for retry in the future, err: Error("invalid value: integer -1, expected usize", line: 0, column: 0), queue: default, jid: 831e821b87d3d6734d1f2254, class: YoHelloWorker, status: fail. Which is good.
So it must be on an internal struct, it's from serde deserializing, and is happening for a usize. Let me go see what sidekiq.rb is doing...
I think sidekiq.rb is Ok too.. they do have a retry function that will decrement (and not necessarily stop at zero), but I wasn't able to get that < 0. So that might not be it?
It might make sense to make retry_count isize though since it's theoretically possible for the input from redis to be malformed.
The timing of these events does match when I had used the retry job within the Sidekiq web interface. I haven't seen it happen since then.
Closing for now. Doesn't seem to be an issue. If someone encounters this, please open and provide some context. I haven't been able to reproduce.