Citygram Sending Failing

Hi everyone.

Last week the digest did not go out when the usual command was run.

This was very likely due to the code being updated to run the codeforamerica branch.

I haven’t been able to reproduce the issue locally, so I tried this morning when the digest should get out.

Once again the digest failed to send. I’m reviewing the logs from today’s failure and will update when I have a solution.

2015-07-08T12:06:42.828309+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:42.828311+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'
2015-07-08T12:06:42.828313+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:141:in `first'
2015-07-08T12:06:42.828314+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:870:in `block in def_finder_method'
2015-07-08T12:06:42.828316+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:462:in `first'
2015-07-08T12:06:42.785857+00:00 app[worker.1]: 2015-07-08T12:06:42.779Z 3 TID-otqcuoaeg WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3e321a0e-8d59-4cc2-ab9b-a0f48b99c1ff", nil], "jid"=>"5ea6d0d0a92021e84a39d98e", "enqueued_at"=>1436357174.757595, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357202.7420816, "retry_count"=>0}
2015-07-08T12:06:42.828318+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:24:in `block (2 levels) in make_tracer_method'
2015-07-08T12:06:42.787834+00:00 app[worker.1]: 2015-07-08T12:06:42.780Z 3 TID-otqcuot4w Citygram::Workers::Notifier JID-e2c2c94d9791ddfadd96f67f INFO: start
2015-07-08T12:06:42.789907+00:00 app[worker.1]: 2015-07-08T12:06:42.786Z 3 TID-otqcuoaeg WARN: Sequel::PoolTimeout
2015-07-08T12:06:42.806316+00:00 app[worker.1]: 2015-07-08T12:06:42.806Z 3 TID-otqcukbjo Citygram::Workers::Notifier JID-997dd5865cbf4e3df09442f8 INFO: start
2015-07-08T12:06:42.816314+00:00 app[worker.1]: 2015-07-08T12:06:42.816Z 3 TID-otqcuoaeg Citygram::Workers::Notifier JID-1e6fc4739f026a94a8f83ef7 INFO: start
2015-07-08T12:06:42.828320+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:69:in `block in trace_execution_scoped'
2015-07-08T12:06:42.828321+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer_helpers.rb:82:in `trace_execution_scoped'
2015-07-08T12:06:42.828323+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:67:in `trace_execution_scoped'
2015-07-08T12:06:42.822528+00:00 app[worker.1]: 2015-07-08T12:06:42.822Z 3 TID-otqcypvq8 Citygram::Workers::Notifier JID-e958c53392ec7155b3fe9b96 INFO: fail: 5.011 sec
2015-07-08T12:06:42.828325+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:23:in `block in make_tracer_method'
2015-07-08T12:06:42.828326+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:471:in `first!'
2015-07-08T12:06:42.828327+00:00 app[worker.1]: /app/app/workers/notifier.rb:9:in `perform'
2015-07-08T12:06:42.828328+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
2015-07-08T12:06:42.828329+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
2015-07-08T12:06:42.828331+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
2015-07-08T12:06:42.827351+00:00 app[worker.1]: 2015-07-08T12:06:42.827Z 3 TID-otqcypvq8 WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3e563d46-5236-4729-a93a-13d7e71c564b", nil], "jid"=>"e958c53392ec7155b3fe9b96", "enqueued_at"=>1436357174.761523, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357202.8213594, "retry_count"=>0}
2015-07-08T12:06:42.828332+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
2015-07-08T12:06:42.828333+00:00 app[worker.1]: /app/app/workers/middleware/database_connections.rb:9:in `call'
2015-07-08T12:06:42.828334+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:42.828336+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'
2015-07-08T12:06:42.828337+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:353:in `perform_action_with_newrelic_trace'
2015-07-08T12:06:42.828339+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:29:in `call'
2015-07-08T12:06:42.828340+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:42.828341+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2015-07-08T12:06:42.828342+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:42.828343+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2015-07-08T12:06:42.828347+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
2015-07-08T12:06:42.828348+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2015-07-08T12:06:42.828349+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:42.828350+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
2015-07-08T12:06:42.828352+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
2015-07-08T12:06:42.828353+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51
:in `block in process'
2015-07-08T12:06:42.828354+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
2015-07-08T12:06:42.828355+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
2015-07-08T12:06:42.828357+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
2015-07-08T12:06:42.828359+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
2015-07-08T12:06:42.828360+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
2015-07-08T12:06:42.828362+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
2015-07-08T12:06:42.828363+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
2015-07-08T12:06:42.828365+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
2015-07-08T12:06:42.828366+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
2015-07-08T12:06:42.828368+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
2015-07-08T12:06:42.840769+00:00 app[worker.1]: 2015-07-08T12:06:42.840Z 3 TID-otqcypvq8 Citygram::Workers::Notifier JID-8e0b3b2681a987025de16dbf INFO: start
2015-07-08T12:06:43.019831+00:00 app[worker.1]: 2015-07-08T12:06:43.019Z 3 TID-otqdb8qe4 Citygram::Workers::Notifier JID-82d8b1ac65e7ae6bda26040a INFO: fail: 5.036 sec
2015-07-08T12:06:43.178586+00:00 app[worker.1]: ** [NewRelic][07/08/15 12:06:43 +0000 worker.1 (3)] WARN : The error reporting queue has reached 20. The error detail for this and subsequent errors will not be transmitted to New Relic until the queued errors have been sent: Sequel::PoolTimeout
2015-07-08T12:06:43.187358+00:00 app[worker.1]: 2015-07-08T12:06:43.187Z 3 TID-otqd21190 WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3e67f30b-03a5-4db3-8a74-737d139aee93", nil], "jid"=>"94c9f4e416a52d1f6d3e52f9", "enqueued_at"=>1436357174.7694535, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357203.1797311, "retry_count"=>0}
2015-07-08T12:06:43.188350+00:00 app[worker.1]: 2015-07-08T12:06:43.188Z 3 TID-otqd21190 WARN: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/connection_pool/threaded.rb:100:in `hold'
2015-07-08T12:06:43.188354+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/database/connecting.rb:229:in `synchronize'
2015-07-08T12:06:43.188355+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/postgres.rb:847:in `literal_string_append'
2015-07-08T12:06:43.188357+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:78:in `literal_append'
2015-07-08T12:06:43.188359+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:484:in `complex_expression_sql_append'
2015-07-08T12:06:43.188361+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/shared/postgres.rb:1216:in `complex_expression_sql_append'
2015-07-08T12:06:43.188363+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/associations.rb:2391:in `complex_expression_sql_append'
2015-07-08T12:06:43.188364+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/sql.rb:107:in `to_s_append'
2015-07-08T12:06:43.016819+00:00 app[worker.1]: ** [NewRelic][07/08/15 12:06:43 +0000 worker.1 (3)] WARN : The error reporting queue has reached 20. The error detail for this and subsequent errors will not be transmitted to New Relic until the queued errors have been sent: Sequel::PoolTimeout
2015-07-08T12:06:43.026220+00:00 app[worker.1]: 2015-07-08T12:06:43.026Z 3 TID-otqdb8qe4 WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3e5a7e4d-43a5-495a-a4e2-da0f8a7655dd", nil], "jid"=>"82d8b1ac65e7ae6bda26040a", "enqueued_at"=>1436357174.7651038, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357203.017166, "retry_count"=>0}
2015-07-08T12:06:43.188366+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:1190:in `literal_expression_append'
2015-07-08T12:06:43.188368+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:85:in `literal_append'
2015-07-08T12:06:43.026231+00:00 app[worker.1]: 2015-07-08T12:06:43.026Z 3 TID-otqdb8qe4 WARN: Sequel::PoolTimeout
2015-07-08T12:06:43.188370+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:163:in `block in sql'
2015-07-08T12:06:43.026304+00:00 app[worker.1]: 2015-07-08T12:06:43.026Z 3 TID-otqdb8qe4 WARN: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/connection_pool/threaded.rb:100:in `hold'
2015-07-08T12:06:43.026307+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/database/connecting.rb:229:in `synchronize'
2015-07-08T12:06:43.188372+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:43.026309+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/postgres.rb:847:in `literal_string_append'
2015-07-08T12:06:43.026311+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:78:in `literal_append'
2015-07-08T12:06:43.188382+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'
2015-07-08T12:06:43.188384+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:141:in `first'
2015-07-08T12:06:43.026313+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:484:in `complex_expression_sql_append'
2015-07-08T12:06:43.188385+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:870:in `block in def_finder_method'
2015-07-08T12:06:43.188387+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:462:in `first'
2015-07-08T12:06:43.188389+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:24:in `block (2 levels) in make_tracer_method'
2015-07-08T12:06:43.188391+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:69:in `block in trace_execution_scoped'
2015-07-08T12:06:43.188393+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer_helpers.rb:82:in `trace_execution_scoped'
2015-07-08T12:06:43.026314+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/shared/postgres.rb:1216:in `complex_expression_sql_append'
2015-07-08T12:06:43.188394+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:67:in `trace_execution_scoped'
2015-07-08T12:06:43.026316+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/associations.rb:2391:in `complex_expression_sql_append'
2015-07-08T12:06:43.026317+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/sql.rb:107:in `to_s_append'
2015-07-08T12:06:43.188396+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:23:in `block in make_tracer_method'
2015-07-08T12:06:43.188398+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:471:in `first!'
2015-07-08T12:06:43.188400+00:00 app[worker.1]: /app/app/workers/notifier.rb:9:in `perform'
2015-07-08T12:06:43.026319+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:1190:in `literal_expression_append'
2015-07-08T12:06:43.026321+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:85:in `literal_append'
2015-07-08T12:06:43.188402+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
2015-07-08T12:06:43.026323+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:163:in `block in sql'
2015-07-08T12:06:43.188403+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
2015-07-08T12:06:43.026324+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:43.026326+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'
2015-07-08T12:06:43.188405+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
2015-07-08T12:06:43.188406+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
2015-07-08T12:06:43.026328+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:141:in `first'
2015-07-08T12:06:43.026329+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:870:in `block in def_finder_method'
2015-07-08T12:06:43.188408+00:00 app[worker.1]: /app/app/workers/middleware/database_connections.rb:9:in `call'
2015-07-08T12:06:43.188410+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.188411+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'
2015-07-08T12:06:43.188414+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:353:in `perform_action_with_newrelic_trace'
2015-07-08T12:06:43.188426+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:29:in `call'
2015-07-08T12:06:43.026331+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:462:in `first'
2015-07-08T12:06:43.026333+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:24:in `block (2 levels) in make_tracer_method'
2015-07-08T12:06:43.026335+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:69:in `block in trace_execution_scoped'
2015-07-08T12:06:43.188428+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.188430+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2015-07-08T12:06:43.026337+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer_helpers.rb:82:in `trace_execution_scoped'
2015-07-08T12:06:43.026343+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:67:in `trace_execution_scoped'
2015-07-08T12:06:43.188431+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.188433+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2015-07-08T12:06:43.026345+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:23:in `block in make_tracer_method'
2015-07-08T12:06:43.188653+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
2015-07-08T12:06:43.026347+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:471:in `first!'
2015-07-08T12:06:43.188656+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2015-07-08T12:06:43.188658+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.188659+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
2015-07-08T12:06:43.026349+00:00 app[worker.1]: /app/app/workers/notifier.rb:9:in `perform'
2015-07-08T12:06:43.026350+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
2015-07-08T12:06:43.188661+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
2015-07-08T12:06:43.026352+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
2015-07-08T12:06:43.026354+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
2015-07-08T12:06:43.026355+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
2015-07-08T12:06:43.188662+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51:in `block in process'
2015-07-08T12:06:43.188664+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
2015-07-08T12:06:43.026357+00:00 app[worker.1]: /app/app/workers/middleware/database_connections.rb:9:in `call'
2015-07-08T12:06:43.026359+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.188666+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
2015-07-08T12:06:43.026361+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'
2015-07-08T12:06:43.188667+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
2015-07-08T12:06:43.188669+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
2015-07-08T12:06:43.188671+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
2015-07-08T12:06:43.188672+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
2015-07-08T12:06:43.026363+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:353:in `perform_action_with_newrelic_trace'
2015-07-08T12:06:43.188674+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
2015-07-08T12:06:43.188675+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
2015-07-08T12:06:43.188677+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
2015-07-08T12:06:43.026364+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:29:in `call'
2015-07-08T12:06:43.188679+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
2015-07-08T12:06:43.203761+00:00 app[worker.1]: 2015-07-08T12:06:43.203Z 3 TID-otqd21190 Citygram::Workers::Notifier JID-f06cb1aaad86b60c15d55554 INFO: start
2015-07-08T12:06:43.026366+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.026368+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2015-07-08T12:06:43.026369+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.026371+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2015-07-08T12:06:43.026379+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
2015-07-08T12:06:43.026380+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2015-07-08T12:06:43.026382+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2
015-07-08T12:06:43.026383+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
2015-07-08T12:06:43.026385+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
2015-07-08T12:06:43.026387+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51:in `block in process'
2015-07-08T12:06:43.026399+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
2015-07-08T12:06:43.026402+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
2015-07-08T12:06:43.026403+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
2015-07-08T12:06:43.026405+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
2015-07-08T12:06:43.026406+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
2015-07-08T12:06:43.026408+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
2015-07-08T12:06:43.026410+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
2015-07-08T12:06:43.026411+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
2015-07-08T12:06:43.026413+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
2015-07-08T12:06:43.026415+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
2015-07-08T12:06:43.043552+00:00 app[worker.1]: 2015-07-08T12:06:43.043Z 3 TID-otqdb8qe4 Citygram::Workers::Notifier JID-3f381a8db560575470e3a3fe INFO: start
2015-07-08T12:06:43.180870+00:00 app[worker.1]: 2015-07-08T12:06:43.180Z 3 TID-otqd21190 Citygram::Workers::Notifier JID-94c9f4e416a52d1f6d3e52f9 INFO: fail: 5.006 sec
2015-07-08T12:06:43.187842+00:00 app[worker.1]: 2015-07-08T12:06:43.187Z 3 TID-otqd21190 WARN: Sequel::PoolTimeout
2015-07-08T12:06:43.091271+00:00 heroku[api]: Starting process with command `bundle exec rake db:migrate` by dkelly@interexchange.org
2015-07-08T12:06:43.634466+00:00 app[worker.1]: 2015-07-08T12:06:43.634Z 3 TID-otqcux2zo Citygram::Workers::Notifier JID-3d7b208ee236586cc2a20a4a INFO: fail: 5.009 sec
2015-07-08T12:06:43.641365+00:00 app[worker.1]: 2015-07-08T12:06:43.641Z 3 TID-otqcux2zo WARN: Sequel::PoolTimeout
2015-07-08T12:06:43.632625+00:00 app[worker.1]: ** [NewRelic][07/08/15 12:06:43 +0000 worker.1 (3)] WARN : The error reporting queue has reached 20. The error detail for this and subsequent errors will not be transmitted to New Relic until the queued errors have been sent: Sequel::PoolTimeout
2015-07-08T12:06:43.641120+00:00 app[worker.1]: 2015-07-08T12:06:43.640Z 3 TID-otqcux2zo WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3e8b07b0-88c7-44f6-90c8-abe49334ce8d", nil], "jid"=>"3d7b208ee236586cc2a20a4a", "enqueued_at"=>1436357174.7731602, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357203.632751, "retry_count"=>0}
2015-07-08T12:06:43.642267+00:00 app[worker.1]: 2015-07-08T12:06:43.642Z 3 TID-otqcux2zo WARN: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/connection_pool/threaded.rb:100:in `hold'
2015-07-08T12:06:43.642269+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/database/connecting.rb:229:in `synchronize'
2015-07-08T12:06:43.642271+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/postgres.rb:847:in `literal_string_append'
2015-07-08T12:06:43.642272+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:78:in `literal_append'
2015-07-08T12:06:43.642273+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:484:in `complex_expression_sql_append'
2015-07-08T12:06:43.642275+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/shared/postgres.rb:1216:in `complex_expression_sql_append'
2015-07-08T12:06:43.642276+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/associations.rb:2391:in `complex_expression_sql_append'
2015-07-08T12:06:43.642277+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/sql.rb:107:in `to_s_append'
2015-07-08T12:06:43.642278+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:1190:in `literal_expression_append'
2015-07-08T12:06:43.642280+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:85:in `literal_append'
2015-07-08T12:06:43.642281+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:163:in `block in sql'
2015-07-08T12:06:43.642282+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:43.642283+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'
2015-07-08T12:06:43.642284+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:141:in `first'
2015-07-08T12:06:43.642285+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:870:in `block in def_finder_method'
2015-07-08T12:06:43.642287+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:462:in `first'
2015-07-08T12:06:43.642288+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:24:in `block (2 levels) in make_tracer_method'
2015-07-08T12:06:43.642290+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:69:in `block in trace_execution_scoped'
2015-07-08T12:06:43.642291+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer_helpers.rb:82:in `trace_execution_scoped'
2015-07-08T12:06:43.642292+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:67:in `trace_execution_scoped'
2015-07-08T12:06:43.642293+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:23:in `block in make_tracer_method'
2015-07-08T12:06:43.642294+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:471:in `first!'
2015-07-08T12:06:43.642296+00:00 app[worker.1]: /app/app/workers/notifier.rb:9:in `perform'
2015-07-08T12:06:43.642297+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
2015-07-08T12:06:43.642298+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
2015-07-08T12:06:43.642299+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
2015-07-08T12:06:43.642300+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
2015-07-08T12:06:43.642301+00:00 app[worker.1]: /app/app/workers/middleware/database_connections.rb:9:in `call'
2015-07-08T12:06:43.642302+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.642303+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'
2015-07-08T12:06:43.642305+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:353:in `perform_action_with_newrelic_trace'
2015-07-08T12:06:43.642306+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:29:in `call'
2015-07-08T12:06:43.642308+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.642309+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2015-07-08T12:06:43.642310+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.642312+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2015-07-08T12:06:43.642710+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
2015-07-08T12:06:43.642712+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2015-07-08T12:06:43.642714+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:43.642715+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
2015-07-08T12:06:43.642716+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
2015-07-08T12:06:43.642717+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51:in `block in process'
2015-07-08T12:06:43.642718+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
2015-07-08T12:06:43.642720+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
2015-07-08T12:06:43.642721+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
2015-07-08T12:06:43.642722+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
2015-07-08T12:06:43.642723+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
2015-07-08T12:06:43.642724+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
2015-07-08T12:06:43.642725+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
2015-07-08T12:06:43.642726+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
2015-07-08T12:06:43.642727+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
2015-07-08T12:06:43.642728+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
2015-07-08T12:06:43.658677+00:00 app[worker.1]: 2015-07-08T12:06:43.658Z 3 TID-otqcux2zo Citygram::Workers::Notifier JID-a1d0563453aec2eedbd88fb4 INFO: start
2015-07-08T12:06:44.052714+00:00 app[worker.1]: ** [NewRelic][07/08/15 12:06:44 +0000 worker.1 (3)] WARN : The error reporting queue has reached 20. The error detail for this and subsequent errors will not be transmitted to New Relic until the queued errors have been sent: Sequel::PoolTimeout
2015-07-08T12:06:44.055109+00:00 app[worker.1]: 2015-07-08T12:06:44.055Z 3 TID-otqcun9do Citygram::Workers::Notifier JID-35321d870ad9279db0f04bcf INFO: fail: 5.004 sec
2015-07-08T12:06:44.058281+00:00 app[worker.1]: 2015-07-08T12:06:44.058Z 3 TID-otqcun9do WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3ea75517-d04a-4f06-9cf9-487acba06cf8", nil], "jid"=>"35321d870ad9279db0f04bcf", "enqueued_at"=>1436357174.776853, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357204.0528553, "retry_count"=>0}
2015-07-08T12:06:44.058291+00:00 app[worker.1]: 2015-07-08T12:06:44.058Z 3 TID-otqcun9do WARN: Sequel::PoolTimeout
2015-07-08T12:06:44.058369+00:00 app[worker.1]: 2015-07-08T12:06:44.058Z 3 TID-otqcun9do WARN: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/connection_pool/threaded.rb:100:in `hold'
2015-07-08T12:06:44.058371+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/database/connecting.rb:229:in `synchronize'
2015-07-08T12:06:44.058372+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/postgres.rb:847:in `literal_string_append'
2015-07-08T12:06:44.058373+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:78:in `literal_append'
2015-07-08T12:06:44.058375+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:484:in `complex_expression_sql_append'
2015-07-08T12:06:44.058376+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/shared/postgres.rb:1216:in `complex_expression_sql_append'
2015-07-08T12:06:44.058377+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/associations.rb:2391:in `complex_expression_sql_append'
2015-07-08T12:06:44.058379+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/sql.rb:107:in `to_s_append'
2015-07-08T12:06:44.058380+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:1190:in `literal_expression_append'
2015-07-08T12:06:44.058381+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:85:in `literal_append'
2015-07-08T12:06:44.058382+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:163:in `block in sql'
2015-07-08T12:06:44.058384+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:44.058385+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'
2015-07-08T12:06:44.058386+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:141:in `first'
2015-07-08T12:06:44.058387+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:870:in `block in def_finder_method'
2015-07-08T12:06:44.058388+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:462:in `first'
2015-07-08T12:06:44.058389+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:24:in `block (2 levels) in make_tracer_method'
2015-07-08T12:06:44.058391+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:69:in `block in trace_execution_scoped'
2015-07-08T12:06:44.058392+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer_helpers.rb:82:in `trace_execution_scoped'
2015-07-08T12:06:44.058393+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/method_tracer.rb:67:in `trace_execution_scoped'
2015-07-08T12:06:44.058394+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/sequel/plugins/newrelic_instrumentation.rb:23:in `block in make_tracer_method'
2015-07-08T12:06:44.058395+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/base.rb:471:in `first!'
2015-07-08T12:06:44.058397+00:00 app[worker.1]: /app/app/workers/notifier.rb:9:in `perform'
2015-07-08T12:06:44.058398+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:75:in `execute_job'
2015-07-08T12:06:44.058399+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:52:in `block (2 levels) in process'
2015-07-08T12:06:44.058400+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `call'
2015-07-08T12:06:44.058401+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:127:in `block in invoke'
2015-07-08T12:06:44.058408+00:00 app[worker.1]: /app/app/workers/middleware/database_connections.rb:9:in `call'
2015-07-08T12:06:44.058410+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:44.058411+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:33:in `block in call'
2015-07-08T12:06:44.058413+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:353:in `perform_action_with_newrelic_trace'
2015-07-08T12:06:44.058414+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/newrelic_rpm-3.10.0.279/lib/new_relic/agent/instrumentation/sidekiq.rb:29:in `call'
2015-07-08T12:06:44.058415+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:44.058416+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/retry_jobs.rb:74:in `call'
2015-07-08T12:06:44.058417+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:44.058418+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:11:in `block in call'
2015-07-08T12:06:44.058423+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/logging.rb:24:in `with_context'
2015-07-08T12:06:44.058424+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/server/logging.rb:7:in `call'
2015-07-08T12:06:44.058425+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:129:in `block in invoke'
2015-07-08T12:06:44.058426+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `call'
2015-07-08T12:06:44.058428+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/chain.rb:132:in `invoke'
2015-07-08T12:06:44.058429+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:51:in `block in process'
2015-07-08T12:06:44.058430+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:98:in `stats'
2015-07-08T12:06:44.058431+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/processor.rb:50:in `process'
2015-07-08T12:06:44.058432+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `public_send'
2015-07-08T12:06:44.058433+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:26:in `dispatch'
2015-07-08T12:06:44.058435+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:122:in `dispatch'
2015-07-08T12:06:44.058436+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:60:in `block in invoke'
2015-07-08T12:06:44.058439+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/cell.rb:71:in `block in task'
2015-07-08T12:06:44.058440+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:357:in `block in task'
2015-07-08T12:06:44.058441+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks.rb:57:in `block in initialize'
2015-07-08T12:06:44.058442+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/tasks/task_fiber.rb:15:in `block in create'
2015-07-08T12:06:44.226808+00:00 app[worker.1]: 2015-07-08T12:06:44.226Z 3 TID-otqcun9do Citygram::Workers::Notifier JID-ffd574d1278532eb04f0ffda INFO: start
2015-07-08T12:06:44Z app[postgres.21702]: [DATABASE] duration: 6319.230 ms  statement:           SELECT events.*
          FROM events
          WHERE events.publisher_id = 1
            AND events.created_at > '2015-07-01 12:06:37.820650+0000'
            AND events.created_at <= '2015-07-08 12:06:37.820792+0000'
            AND ST_Intersects(events.geom, 'SRID=4326;POLYGON((-73.9601495185643 40.681030714416835,-73.95060648143566 40.681030714416835,-73.95060648143566 40.68826728558317,-73.9601495185643 40.68826728558317,-73.9601495185643 40.681030714416835))'::geometry)
          ORDER BY events.created_at DESC
2015-07-08T12:06:44.412308+00:00 app[worker.1]: 2015-07-08T12:06:44.412Z 3 TID-otqcue6l8 Citygram::Workers::Notifier JID-e17dd576514956f75584ecc5 INFO: done: 11.62 sec
2015-07-08T12:06:44.614925+00:00 app[worker.1]: 2015-07-08T12:06:44.614Z 3 TID-otqcux2zo Citygram::Workers::Notifier JID-a1d0563453aec2eedbd88fb4 INFO: done: 0.956 sec
2015-07-08T12:06:44.458799+00:00 app[worker.1]: 2015-07-08T12:06:44.458Z 3 TID-otqcue6l8 Citygram::Workers::Notifier JID-7cd4254f4df6ac5f2eb9a81c INFO: start
2015-07-08T12:06:44.628427+00:00 app[worker.1]: 2015-07-08T12:06:44.628Z 3 TID-otqcux2zo Citygram::Workers::Notifier JID-7802465233e99a1520ea0165 INFO: start
2015-07-08T12:06:44.734672+00:00 app[worker.1]: ** [NewRelic][07/08/15 12:06:44 +0000 worker.1 (3)] WARN : The error reporting queue has reached 20. The error detail for this and subsequent errors will not be transmitted to New Relic until the queued errors have been sent: Sequel::PoolTimeout
2015-07-08T12:06:44.752714+00:00 app[worker.1]: 2015-07-08T12:06:44.752Z 3 TID-otqcukp6s WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["3f01f14a-8960-4d68-a77c-54a2282ddeff", nil], "jid"=>"3142eaef995d8132c90c8d5e", "enqueued_at"=>1436357174.7806375, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436357204.7348378, "retry_count"=>0}
2015-07-08T12:06:44.736260+00:00 app[worker.1]: 2015-07-08T12:06:44.736Z 3 TID-otqcukp6s Citygram::Workers::Notifier JID-3142eaef995d8132c90c8d5e INFO: fail: 5.008 sec
2015-07-08T12:06:44.753507+00:00 app[worker.1]: 2015-07-08T12:06:44.753Z 3 TID-otqcukp6s WARN: Sequel::PoolTimeout
2015-07-08T12:06:44.753599+00:00 app[worker.1]: 2015-07-08T12:06:44.753Z 3 TID-otqcukp6s WARN: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/connection_pool/threaded.rb:100:in `hold'
2015-07-08T12:06:44.753601+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/database/connecting.rb:229:in `synchronize'
2015-07-08T12:06:44.753602+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/postgres.rb:847:in `literal_string_append'
2015-07-08T12:06:44.753604+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:78:in `literal_append'
2015-07-08T12:06:44.753605+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:484:in `complex_expression_sql_append'
2015-07-08T12:06:44.753607+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/adapters/shared/postgres.rb:1216:in `complex_expression_sql_append'
2015-07-08T12:06:44.753608+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/associations.rb:2391:in `complex_expression_sql_append'
2015-07-08T12:06:44.753609+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/sql.rb:107:in `to_s_append'
2015-07-08T12:06:44.753611+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:1190:in `literal_expression_append'
2015-07-08T12:06:44.753612+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/sql.rb:85:in `literal_append'
2015-07-08T12:06:44.753613+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:163:in `block in sql'
2015-07-08T12:06:44.753614+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `each'
2015-07-08T12:06:44.753615+00:00 app[worker.1]: /app/vendor/bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/placeholder_literalizer.rb:155:in `sql'

Looking at Mandrill it seems they did go out today. Not sure why it’s reporting failures, I’ll keep this post updated.

1 Like

Logs show the same error when the usual command was run this morning. I.e. today’s digest did not go out. @dirkkelly Any ideas?

I can confirm that I didn’t get my citygram. :frowning:

I am thinking over your comment about environment. It seems very unlikely,
but I’m wondering if maybe a permissions issue to do with workers.

I’m going to set mandril to test mode and do some debugging in production
to try understand the issue.

@dirkkelly - At around 9AM.

It has to do with the Workers–more specifically, it seems like with Sequel. I don’t know enough about Sequel and ConnectionPool to make sense of it

Here’s the error (pulled from New Relic)–

…s/sequel-4.12.0/lib/sequel/connection_pool/
threaded.rb: 100:in `hold'
…0/gems/sequel-4.12.0/lib/sequel/database/
connecting.rb: 229:in `synchronize'
…0.0/gems/sequel-4.12.0/lib/sequel/adapters/
postgres.rb: 847:in `literal_string_append'
…uby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/
sql.rb:  78:in `literal_append'
…uby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/
sql.rb: 484:in `complex_expression_sql_append'
…s/sequel-4.12.0/lib/sequel/adapters/shared/
postgres.rb:1216:in `complex_expression_sql_append'
….0/gems/sequel-4.12.0/lib/sequel/model/
associations.rb:2391:in `complex_expression_sql_append'
…bundle/ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/
sql.rb: 107:in `to_s_append'
…uby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/
sql.rb:1190:in `literal_expression_append'
…uby/2.0.0/gems/sequel-4.12.0/lib/sequel/dataset/
sql.rb:  85:in `literal_append'
…l-4.12.0/lib/sequel/dataset/
placeholder_literalizer.rb: 163:in `block in sql'
…l-4.12.0/lib/sequel/dataset/
placeholder_literalizer.rb: 155:in `each'
…l-4.12.0/lib/sequel/dataset/
placeholder_literalizer.rb: 155:in `sql'
…l-4.12.0/lib/sequel/dataset/
placeholder_literalizer.rb: 141:in `first'
…ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/
base.rb: 870:in `block in def_finder_method'
…ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/
base.rb: 462:in `first'
…0.0.279/lib/sequel/plugins/
newrelic_instrumentation.rb:  24:in `block (2 levels) in make_tracer_method'
…0.0.279/lib/sequel/plugins/
newrelic_instrumentation.rb:  23:in `block in make_tracer_method'
…ruby/2.0.0/gems/sequel-4.12.0/lib/sequel/model/
base.rb: 471:in `first!'
                           /app/app/workers/
notifier.rb:   9:in `perform'
…ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
processor.rb:  75:in `execute_job'
…ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
processor.rb:  52:in `block (2 levels) in process'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 127:in `call'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 127:in `block in invoke'
    /app/app/workers/middleware/
database_connections.rb:   9:in `call'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 129:in `block in invoke'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 129:in `block in invoke'
…ekiq-3.3.2/lib/sidekiq/middleware/server/
retry_jobs.rb:  74:in `call'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 129:in `block in invoke'
…sidekiq-3.3.2/lib/sidekiq/middleware/server/
logging.rb:  11:in `block in call'
…e/ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
logging.rb:  24:in `with_context'
…sidekiq-3.3.2/lib/sidekiq/middleware/server/
logging.rb:   7:in `call'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 129:in `block in invoke'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 132:in `call'
…0.0/gems/sidekiq-3.3.2/lib/sidekiq/middleware/
chain.rb: 132:in `invoke'
…ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
processor.rb:  51:in `block in process'
…ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
processor.rb:  98:in `stats'
…ruby/2.0.0/gems/sidekiq-3.3.2/lib/sidekiq/
processor.rb:  50:in `process'
…uby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
calls.rb:  26:in `public_send'
…uby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
calls.rb:  26:in `dispatch'
…uby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
calls.rb: 122:in `dispatch'
…ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
cell.rb:  60:in `block in invoke'
…ruby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
cell.rb:  71:in `block in task'
…uby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
actor.rb: 357:in `block in task'
…uby/2.0.0/gems/celluloid-0.16.0/lib/celluloid/
tasks.rb:  57:in `block in initialize'
…ems/celluloid-0.16.0/lib/celluloid/tasks/
task_fiber.rb:  15:in `block in create'

Also, from PAPERTRAIL (thank you for adding it!), this is the error that repeats at least 7 times.

Jul 15 06:09:09 citygram-nyc app/worker.1:  2015-07-15T13:09:09.643Z 3 TID-ousdt8f6w WARN: {"retry"=>5, "queue"=>"default", "class"=>"Citygram::Workers::Notifier", "args"=>["90e0ea11-4536-4752-86f9-bf18f2a8c772", nil], "jid"=>"8ba328929bd4872c33a85544", "enqueued_at"=>1436964706.2984443, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1436964767.6666646, "retry_count"=>5, "retried_at"=>1436965749.6196437} 

I’m currently working on this issue https://github.com/BetaNYC/citygram-nyc/issues/57

Anyone who is interested can follow along through github, if you’d like to pair with me shoot me an email citygram@dirkkelly.com

My partner received her email this week

Date: July 15, 2015 at 9:06:31 AM EDT
Subject: Citygram 311 Service Requests notifications
Latest 311 Service Requests for

My belief is that sidekick is trying to read the database but doesn’t have access to the connection pool because of misconfigured workers.

I’m reviewing configuration.

@everyone I’m very sorry, it looks like I’ve haphazardly released code to production that is not in staging. The differences are immense, most notably different versions of Ruby are being used.

I now understand why I haven’t been able to reproduce the failures in staging, I’ll continue working, however in the mean time I will be reverting production to the version on staging so that future runs will not fail.

Cheers

Still failing on the old version of code

Jul 19 09:18:28 citygram-nyc app/worker.1:  2015-07-19T16:18:28.232Z 3 TID-oqwq0m9yw WARN: {"class"=>"Citygram::Workers::Notifier", "args"=>["771ea3dc-5fbe-41ac-9b0a-651e1719c01a", nil], "retry"=>5, "queue"=>"default", "jid"=>"39cac6c39832853ef311cc11", "enqueued_at"=>1437322699.4492602, "error_message"=>"Sequel::PoolTimeout", "error_class"=>"Sequel::PoolTimeout", "failed_at"=>1437322708.1816394, "retry_count"=>0} 

And yet Mandrill sent out some messages, looks like it fails on a smaller subset of recipients

Mandrill is in test mode btw

I crashed the server, database is out of sync with the version of master on staging.

Sorry team, reverting and rethinking.

Actually, it wasn’t that I had deployed non-staging to production, it’s that I hadn’t.

dirkkelly@spring:~/src/betanyc/citygram-nyc
master (dk) [$]
$ git diff production/master staging/master
diff --git a/.env.sample b/.env.sample
index 647196a…c4e01fa 100644
— a/.env.sample
+++ b/.env.sample
@@ -12,3 +12,4 @@ SMTP_PASSWORD=dev-smtp-password
SMTP_DOMAIN=mydomain.com
SMTP_FROM_ADDRESS=citygram@example.com
DEV_EMAIL_RECIPIENT=thedeveloper@example.com
+DIGEST_DAY=Sun
diff --git a/.ruby-version b/.ruby-version
index 503328d…eca07e4 100644
— a/.ruby-version
+++ b/.ruby-version
@@ -1 +1 @@
-2.0.0-p598
+2.1.2
diff --git a/.travis.yml b/.travis.yml
index 42ae269…96a6ff3 100644
— a/.travis.yml
+++ b/.travis.yml
@@ -4,11 +4,14 @@ rvm:

  • 2.1.1
  • 2.1.2
  • ruby-head
    +addons:
  • postgresql: "9.3"
    matrix:
    allow_failures:
    • rvm: ruby-head
    • rvm: 2.1.2
      script:
    • psql -V
    • cp .env.sample .env
    • bundle exec rake db:create db:migrate DATABASE_URL=postgres://localhost/citygram_test
    • bundle exec rake
      diff --git a/Gemfile b/Gemfile
      index bee9321…8edc22c 100644
      — a/Gemfile
      +++ b/Gemfile
      @@ -3,17 +3,17 @@ source 'https://rubygems.org
      if ENV[‘CI’]
      ruby RUBY_VERSION
      else

Sending is now working with master code, some of the data needs to be fixed to work with the new code. Currently working on tagging publishers to nyc;

Have opened a new issue, finding bugs on cfa/master https://github.com/BetaNYC/citygram-nyc/issues/60


Taking a break, hope to work on this more tonight.

Digest sending still not fixed, but I’ve put production back into operation and tested that subscriptions are working and sending confirmation emails.

Still hunting down the reason for digest failure, will be able to use staging from here on out though.

Cleaned up the logs at the expense of browser tracking, shouldn’t see those warns on frozen routes in production.

I believe I have a fix sitting in production

We’ll be able to test wed I suppose? Maybe we should move our notifications to Thursday so we can work on things the night before at beta nyc?