Faktory::ParseError

[ffiller]

Hi @mperham,

We've been consistently seeing occurrences of [Faktory::ParseError](https://github.com/contribsys/faktory_worker_ruby/blob/master/lib/faktory/client.rb#L341), for roughly 0.01% of our Jobs.

line.strip is always blank. The comment suggests that, "this is bad, indicates we need to reset the socket and start fresh".

Do you have any experience with what usually triggers these and any suggestion for an improvement we could PR up and submit to handle these Parse Errors? (or other recommendation on how to handle on our end)

Thanks!

[mperham]

Can you give me a full backtrace?

[ffiller]

[PROJECT_ROOT]/app/controllers/clearbit_controller.rb:12 :in `receive`
[GEM_ROOT]/bundler/gems/faktory_worker_ruby-f7f87837fdf9/lib/faktory/client.rb:341 :in `result`
[GEM_ROOT]/bundler/gems/faktory_worker_ruby-f7f87837fdf9/lib/faktory/client.rb:346 :in `ok`
[GEM_ROOT]/bundler/gems/faktory_worker_ruby-f7f87837fdf9/lib/faktory/client.rb:151 :in `block in push`
[GEM_ROOT]/bundler/gems/faktory_worker_ruby-f7f87837fdf9/lib/faktory/client.rb:297 :in `transaction`
[GEM_ROOT]/bundler/gems/faktory_worker_ruby-f7f87837fdf9/lib/faktory/client.rb:149 :in `push`
/bare_shared/lib/message_queue.rb:90 :in `push`
[PROJECT_ROOT]/app/controllers/application_controller.rb:64 :in `queue`
[PROJECT_ROOT]/app/controllers/clearbit_controller.rb:12 :in `receive`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/basic_implicit_render.rb:6 :in `send_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/abstract_controller/base.rb:195 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/rendering.rb:30 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/abstract_controller/callbacks.rb:42 :in `block in process_action`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/callbacks.rb:135 :in `run_callbacks`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/abstract_controller/callbacks.rb:41 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/rescue.rb:22 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/instrumentation.rb:33 :in `block in process_action`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/notifications.rb:180 :in `block in instrument`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/notifications/instrumenter.rb:24 :in `instrument`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/notifications.rb:180 :in `instrument`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/instrumentation.rb:32 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal/params_wrapper.rb:245 :in `process_action`
[GEM_ROOT]/gems/activerecord-6.0.3.3/lib/active_record/railties/controller_runtime.rb:27 :in `process_action`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/abstract_controller/base.rb:136 :in `process`
[GEM_ROOT]/gems/actionview-6.0.3.3/lib/action_view/rendering.rb:39 :in `process`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal.rb:190 :in `dispatch`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_controller/metal.rb:254 :in `dispatch`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/routing/route_set.rb:50 :in `dispatch`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/routing/route_set.rb:33 :in `serve`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/journey/router.rb:49 :in `block in serve`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/journey/router.rb:32 :in `each`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/journey/router.rb:32 :in `serve`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/routing/route_set.rb:834 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/tempfile_reaper.rb:15 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/etag.rb:27 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/conditional_get.rb:40 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/head.rb:12 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/http/content_security_policy.rb:18 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:266 :in `context`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/session/abstract/id.rb:260 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/cookies.rb:648 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/callbacks.rb:27 :in `block in call`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/callbacks.rb:101 :in `run_callbacks`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/callbacks.rb:26 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/actionable_exceptions.rb:17 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/debug_exceptions.rb:32 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/show_exceptions.rb:33 :in `call`
[GEM_ROOT]/gems/railties-6.0.3.3/lib/rails/rack/logger.rb:37 :in `call_app`
[GEM_ROOT]/gems/railties-6.0.3.3/lib/rails/rack/logger.rb:26 :in `block in call`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/tagged_logging.rb:80 :in `block in tagged`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/tagged_logging.rb:28 :in `tagged`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/tagged_logging.rb:80 :in `tagged`
[GEM_ROOT]/gems/railties-6.0.3.3/lib/rails/rack/logger.rb:26 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/remote_ip.rb:81 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/request_id.rb:27 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/method_override.rb:24 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/runtime.rb:22 :in `call`
[GEM_ROOT]/gems/activesupport-6.0.3.3/lib/active_support/cache/strategy/local_cache_middleware.rb:29 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/executor.rb:14 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/static.rb:126 :in `call`
[GEM_ROOT]/gems/rack-2.2.3/lib/rack/sendfile.rb:110 :in `call`
[GEM_ROOT]/gems/actionpack-6.0.3.3/lib/action_dispatch/middleware/host_authorization.rb:76 :in `call`
[GEM_ROOT]/gems/railties-6.0.3.3/lib/rails/engine.rb:527 :in `call`
[GEM_ROOT]/gems/puma-4.3.6/lib/puma/configuration.rb:228 :in `call`
[GEM_ROOT]/gems/puma-4.3.6/lib/puma/server.rb:713 :in `handle_request`
[GEM_ROOT]/gems/puma-4.3.6/lib/puma/server.rb:472 :in `process_client`
[GEM_ROOT]/gems/puma-4.3.6/lib/puma/server.rb:328 :in `block in run`
[GEM_ROOT]/gems/puma-4.3.6/lib/puma/thread_pool.rb:134 :in `block in spawn_thread`

[mperham]

I’m guessing you are using the client in an thread unsafe manner. You need to use a connection pool within lib/message_queue.rb and not a Faktory::Client singleton. Show us that code.

[ffiller]

Jeez you're right 🤦 Not sure why I didn't see that. Thanks!