Qless rack middleware: CommandError: bad argument to 'decode'

Question

Qless rack middleware: CommandError: bad argument to 'decode'

canadaduane opened this issue 11 years ago · 9 comments

When I try to visit the home page of the Qless rack middleware, I get the exception below, indicating that a string is expected but it was passed a boolean. All other pages (queues, workers) except 'track' appear to work properly. The 'track' page has the same error.

Running on master HEAD.

Redis::CommandError - ERR Error running script (call to f_6c34b124c452c1cd5a2aa32d8b89bcac6e5488e3): user_script:68: bad argument #1 to 'decode' (string expected, got boolean):
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis/client.rb:97:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis.rb:2189:in `block in _eval'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis.rb:37:in `block in synchronize'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis.rb:37:in `synchronize'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis.rb:2188:in `_eval'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/redis-3.0.7/lib/redis.rb:2240:in `evalsha'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/lua_script.rb:34:in `_call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/lua_script.rb:23:in `rescue in call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/lua_script.rb:20:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless.rb:53:in `tracked'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server.rb:97:in `tracked'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server/views/overview.erb:55:in `block in singletonclass'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server/views/overview.erb:65531:in `instance_eval'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server/views/overview.erb:65531:in `singletonclass'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server/views/overview.erb:65529:in `__tilt_70189769247960'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/tilt-1.4.1/lib/tilt/template.rb:170:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/tilt-1.4.1/lib/tilt/template.rb:170:in `evaluate'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/tilt-1.4.1/lib/tilt/template.rb:103:in `render'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:711:in `render'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:597:in `erb'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/qless-0.9.3/lib/qless/server.rb:154:in `block in <class:Server>'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:1293:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:1293:in `block in compile!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:860:in `[]'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:860:in `block (3 levels) in route!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:876:in `route_eval'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:860:in `block (2 levels) in route!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:897:in `block in process_route'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:895:in `catch'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:895:in `process_route'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:859:in `block in route!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:858:in `each'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:858:in `route!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:963:in `block in dispatch!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `block in invoke'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `catch'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `invoke'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:960:in `dispatch!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:794:in `block in call!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `block in invoke'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `catch'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:946:in `invoke'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:794:in `call!'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:780:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/xss_header.rb:18:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/path_traversal.rb:16:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/json_csrf.rb:18:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/base.rb:50:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/base.rb:50:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-protection-1.5.2/lib/rack/protection/frame_options.rb:31:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-1.5.2/lib/rack/nulllogger.rb:9:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/showexceptions.rb:21:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/sinatra-1.3.6/lib/sinatra/base.rb:124:in `call'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/connection.rb:81:in `block in pre_process'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/connection.rb:79:in `catch'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/connection.rb:79:in `pre_process'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/connection.rb:54:in `process'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/connection.rb:39:in `receive_data'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run_machine'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:187:in `run'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/backends/base.rb:63:in `start'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/thin-1.5.1/lib/thin/server.rb:159:in `start'
    /Users/duane/.rbenv/versions/1.9.3-p194/lib/ruby/gems/1.9.1/gems/rack-1.5.2/lib/rack/handler/thin.rb:16:in `run'
    bin/sif:169:in `<main>'

Answer 1 · 2014-01-23T17:48:57.000Z

I switched back to 0.9.3 and found a similar error. In v0.9.3, the error appears to be caused by a nil history in get:

ERR Error running script (call to f_f7526d197070c9e82c28fad331b4c020585aad20): user_script:33: bad argument #1 to 'decode' (string expected, got boolean)

where line 33 corresponds to get.lua:

  history      = cjson.decode(job[12]),

adding "or '[]'" seems to fix this for me:

  history      = cjson.decode(job[12] or '[]'),

Answer 2 · 2014-01-23T21:42:30.000Z

I'm working on some explanation for the above errors. As far as I can tell, the 'history' key of each job is not populated until some future point in the Qless worker process. So when a job is first placed on the queue, like the following one, it has no 'history' key:

hgetall 'ql:j:025E3C463E4C45D3BF9D4592C8DFD782'
 1) "remaining"
 2) "5"
 3) "jid"
 4) "025E3C463E4C45D3BF9D4592C8DFD782"
 5) "data"
 6) "{\"request_group_ids\":[\"23C5381066A401311C7414109FD501C1\",\"2414BF9066A401311C7414109FD501C1\",\"24643A4066A401311C7414109FD501C1\",\"24A929D066A401311C7414109FD501C1\",\"24F77C3066A401311C7414109FD501C1\",\"253DC88066A401311C7414109FD501C1\",\"258D07C066A401311C7414109FD501C1\",\"261A6BA066A401311C7414109FD501C1\"],\"output_dir\":\"bin\\/..\\/hopper\\/transform\\/025E3C463E4C45D3BF9D4592C8DFD782\",\"responses_dir\":\"bin\\/..\\/hopper\\/responses\"}"
 7) "queue"
 8) "default"
 9) "expires"
10) "0"
11) "priority"
12) "0"
13) "klass"
14) "SIFLord::Transformer"
15) "state"
16) "depends"
17) "tags"
18) "{}"
19) "worker"
20) ""
21) "retries"
22) "5"

It appears that a 'history' key is assumed, however, because code such as https://github.com/seomoz/qless-core/blob/534fac347c245a9a62100586e8ed662039ec6584/pop.lua#L208 (and line 215) will fail when history is nil and the "or '{}'" fallback is triggered (note: if history is an empty lua table, then history[#history] is nil, and history[#history]['worker'] and history[#history]['put'] are invalid and will trigger an error).

Answer 3 · 2014-01-30T23:47:50.000Z

I was experiencing the same thing and finally figured out what was going on (not sure if this will apply to you):

The project I'm using qless with is making use of an earlier revision, but I had the latest gem installed system wide. These two conflicted, and so I had to remove the latest gems from my system gems and install the old revision.

Answer 4 · 2014-01-30T23:55:46.000Z

Yeah, that applies. I'll test to see if I can reproduce with only one version available system wide.

Answer 5 · 2014-06-19T03:16:11.000Z

Was there any outcome to this?

I am getting the error:
ERR Error running script (call to f_f7526d197070c9e82c28fad331b4c020585aad20): @user_script:33: user_script:33: bad argument #1 to 'decode' (string expected, got boolean) (Redis::CommandError)

Answer 6 · 2014-06-19T03:36:12.000Z

I am trying to read the job with client.jobs['e6d8ad4447e1468db4464529687fa127']

The job is complete.

Answer 7 · 2014-06-19T03:50:50.000Z

It seems that i can make the issue go away by adding the following:

Answer 8 · 2014-06-19T04:04:29.000Z

I have to move to 0.10.1 pre to resolve the issue.

Any ideas what what may have been causing this?

Answer 9 · 2014-08-14T17:26:32.000Z

Having this problem as well.