stefanwille / crystal-redis

Full featured Redis client for Crystal
MIT License
381 stars 61 forks source link

Weird sporadic cast error with HGET/HGETALL #130

Closed atlantis closed 1 year ago

atlantis commented 1 year ago

Hi and thanks for a great library! I'm having a very odd error where very rarely HGET returns 0 instead of a string, and throws a cast error...

I added the following to value_oriented.cr:45

puts "*** #{request.inspect}"
puts res.inspect
puts res.class.inspect

And here's an example log set:

app_1            | "1665178626"
app_1            | String
app_1            | *** ["HGET", "development:v1:activity:5ea776066168b03c1b1c5539:device", "632e3b3e83f24b1c1dde0895"]
app_1            | "1665178626"
app_1            | String
app_1            | *** ["HGET", "development:v1:activity:5ea776066168b03c1b1c5539:actor", "6e6c892cec44a92ad9b64544"]
app_1            | "1665178626"
app_1            | String
app_1            | 2022-10-07T21:41:21.576700Z   WARN - update_last_active error for development:v1:activity:5ea776066168b03c1b1c5539:actor : 6e6c892cec44a92ad9b64544 cast from String to Int64 failed, at /var/watchmark/lib/redis/src/redis/command_execution/value_oriented.cr:13:9:13
app_1            | *** ["HGET", "development:v1:activity:5ea776066168b03c1b1c5539:actor", "6e6c892cec44a92ad9b64544"]
app_1            | 0
app_1            | Int64

It will fail once and then the next request will pull the value just fine!

Any ideas what might be going on? It would be fairly simple to suppress the error but I do need an accurate value back and right now it's hit and miss... here's the code I'm using in Crystal 1.0:

module ActivityCache
  extend self

  def redis_namespace(name)
    "#{ENVIRONMENT}:v1:activity:#{name}"
  end

  def last_active_at( key : String?, id : String? )
    if (redis = self.connection) && key && id
      if timestamp = redis.hget(self.redis_namespace(key), id)
        if timestamp_i = timestamp.to_i?
          return Time.unix(timestamp_i)
        end
      end
    end

    nil
  rescue ex
    Log.warn { "last_active_at error for #{self.redis_namespace(key)} : #{id} #{ex}" }
    nil
  end

  def update_last_active( key : String, id : String, time = Time.utc )
    if redis = self.connection
      if self.needs_update( key, id )
        redis.hset self.redis_namespace(key), id, time.to_unix.to_s
      end
    end
  rescue ex
    Log.warn { "update_last_active error for #{self.redis_namespace(key)} : #{id} #{ex}" }
    nil
  end

  def connection
    @@redis ||= Redis.new(
      host: REDIS_HOST,
      port: REDIS_PORT,
      password: REDIS_TOKEN
    )
  end

  def needs_update(key, id, seconds = 60)
    if last_active = self.last_active_at(key, id).try(&.to_unix) || 0
      now = Time.utc
      current_minute = (now.to_unix - (now.to_unix % seconds))
      last_updated_minute = (last_active - (last_active % seconds))

      current_minute != last_updated_minute
    else
      true
    end
  end
end
kostya commented 1 year ago

have you any small example to reproduce? may be your key somehow expire?

atlantis commented 1 year ago

Going to close this issue because I think it was possibly user error - I was using this with Kemal, and the redis object apparently just can't be shared safely between fibers...