Getting strange errors while trying to send a message through Twilio

Yesterday we did a big upgrade for our backend, and now we get some strange errors, and I have no idea what it is. Errors appear to be trying to send a message through the Twilio client. In addition, everything happens in our sidekiq queue, which we believe because of these errors. On this sidebar, there are several things that await there. Here are some of the errors we see:

  • IOError: private thread
  • OpenSSL :: SSL :: SSLError: SSL_connect returned = 1 errno = 0 state = SSLv3 read server greeting A: unknown warning type
  • Net :: ReadTimeout: Net :: ReadTimeout
  • EOFError: end of file reached
  • IOError: attempt to read the body outside the block.
  • Errno :: EBADF: bad file descriptor

This is not so much for us in the past, and now they happen very often. Here's the stacktrace for the IOError: closed thread error:

/vendor/ruby-2.1.0/lib/ruby/2.1.0/net/protocol.rb:155 in "select" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/protocol.rb:155 in "rescue in rbuf_fill" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/protocol.rb:152 in "rbuf_fill" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/protocol.rb:134 in "readuntil" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/protocol.rb:144 in "readline" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http/response.rb:39 in "read_status_line" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http/response.rb:28 in "read_new" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1408 in "block in transport_request" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1405 in "catch" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1405 in "transport_request" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1378 in "request" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:27 in "block (2 levels) in request_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent.rb:454 in "disable_all_tracing" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:26 in "block in request_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/cross_app_tracing.rb:38 in "tl_trace_http_request" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:23 in "request_with_newrelic_trace" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1371 in "block in request" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:853 in "start" /vendor/ruby-2.1.0/lib/ruby/2.1.0/net/http.rb:1369 in "request" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:27 in "block (2 levels) in request_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent.rb:454 in "disable_all_tracing" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:26 in "block in request_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/cross_app_tracing.rb:43 in "tl_trace_http_request" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/net.rb:23 in "request_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/twilio-ruby-3.11.5/lib/twilio-ruby/rest/client.rb:216 in "connect_and_send" /vendor/bundle/ruby/2.1.0/gems/twilio-ruby-3.11.5/lib/twilio-ruby/rest/client.rb:168 in "block (2 levels) in <class:Client>" /vendor/bundle/ruby/2.1.0/gems/twilio-ruby-3.11.5/lib/twilio-ruby/rest/list_resource.rb:91 in "create" /app/models/message_sender.rb:142 in "send_message_with_twilio!" /app/models/message_sender.rb:66 in "send_sms" /app/models/message_sender.rb:37 in "send_now" /app/models/message_sender.rb:19 in "block (2 levels) in save_and_send_from_job" /vendor/bundle/ruby/2.1.0/gems/activerecord-4.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:201 in "block in transaction" /vendor/bundle/ruby/2.1.0/gems/activerecord-4.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:209 in "within_new_transaction" /vendor/bundle/ruby/2.1.0/gems/activerecord-4.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:201 in "transaction" /vendor/bundle/ruby/2.1.0/gems/activerecord-4.1.6/lib/active_record/transactions.rb:208 in "transaction" /app/models/message_sender.rb:17 in "block in save_and_send_from_job" /app/models/message_sender.rb:16 in "each" /app/models/message_sender.rb:16 in "save_and_send_from_job" /app/workers/send_single_sms_worker.rb:8 in "perform" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:49 in "block (3 levels) in process" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:122 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:122 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/sidekiq.rb:33 in "block in call" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:365 in "perform_action_with_newrelic_trace" /vendor/bundle/ruby/2.1.0/gems/newrelic_rpm-3.9.5.251/lib/new_relic/agent/instrumentation/sidekiq.rb:29 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidetiq-0.6.1/lib/sidetiq/middleware/history.rb:8 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-history-0.0.1/lib/sidekiq/history/middleware.rb:26 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/server/active_record.rb:6 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/server/retry_jobs.rb:62 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/bundler/gems/sidekiq-failures-485c6e56e306/lib/sidekiq/failures/middleware.rb:9 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/server/logging.rb:11 in "block in call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/logging.rb:22 in "with_context" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/server/logging.rb:7 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:124 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:127 in "call" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/middleware/chain.rb:127 in "invoke" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:48 in "block (2 levels) in process" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:108 in "stats" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:47 in "block in process" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:86 in "do_defer" /vendor/bundle/ruby/2.1.0/gems/sidekiq-2.17.7/lib/sidekiq/processor.rb:37 in "process" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26 in "public_send" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26 in "dispatch" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122 in "dispatch" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60 in "block in invoke" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71 in "block in task" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357 in "block in task" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57 in "block in initialize" /vendor/bundle/ruby/2.1.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15 in "block in create" 
+5
source share
1 answer

Most likely, I found a problem, since we have not had any problems since it was fixed. It turns out that Twilio Client is not thread safe, and we tried to hammer the same @client with a bunch of different threads. The fix was for us to create a new twilio client every time we need it.

+10
source

Source: https://habr.com/ru/post/1215712/


All Articles