getlago / lago

Open Source Metering and Usage Based Billing API ⭐️ Consumption tracking, Subscription management, Pricing iterations, Payment orchestration & Revenue analytics
https://www.getlago.com
GNU Affero General Public License v3.0
7.04k stars 310 forks source link

[BUG]: one exception in clock causes it to break permanently, such as a transient high latency to redis issue #357

Closed doctorpangloss closed 5 months ago

doctorpangloss commented 5 months ago

Describe the bug

I, [2024-05-27T19:25:56.001131 #7]  INFO -- : Triggering 'schedule:activate_subscriptions'
E, [2024-05-27T19:25:56.204568 #7] ERROR -- : [ActiveJob] Failed enqueuing Clock::ActivateSubscriptionsJob to Sidekiq(clock): Redis::TimeoutError (Waited 0.1 seconds)
E, [2024-05-27T19:25:56.204776 #7] ERROR -- : Waited 0.1 seconds (Redis::TimeoutError)
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:140:in `block in fill_buffer'/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `loop'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `fill_buffer'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:114:in `ensure_remaining'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:85:in `getbyte'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:113:in `parse'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:50:in `load'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection.rb:94:in `read'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/connection_mixin.rb:31:in `call'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:239:in `block (2 levels) in call_v'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/middlewares.rb:16:in `call'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:238:in `block in call_v'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:643:in `ensure_connected'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:237:in `call_v'
/usr/local/bundle/gems/redis-5.0.6/lib/redis/client.rb:73:in `call_v'
/usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:167:in `block in send_command'
/usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `synchronize'
/usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `send_command'
/usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:110:in `_eval'
/usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:97:in `evalsha'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block (2 levels) in lock'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:152:in `with'
#<Thread:0x000077641f8b2bd0 /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:426 run> terminated with exception (report_on_exception is true):
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block in lock'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:208:in `recover_from_script_flush'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:170:in `lock'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block (2 levels) in lock_instances'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `select'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block in lock_instances'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:311:in `timed'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:257:in `lock_instances'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:232:in `block in try_lock_instances'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `times'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `try_lock_instances'
/usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:69:in `lock'
/usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:24:in `lock'
/usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:59:in `before_enqueue'
/usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/active_job_patch.rb:50:in `block (2 levels) in <module:ActiveJobPatch>'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `instance_exec'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `block in make_lambda'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:199:in `block (2 levels) in halting'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:687:in `block (2 levels) in default_terminator'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `catch'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `block in default_terminator'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:200:in `block in halting'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `block in invoke_before'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `each'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `invoke_before'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:116:in `block in run_callbacks'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:25:in `block in instrument'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `block in instrument'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `instrument'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:35:in `instrument'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:9:in `block (2 levels) in <module:Instrumentation>'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
/usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `block in tag_logger'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `block in tagged'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:37:in `tagged'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `tagged'
/usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `tag_logger'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
/usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:138:in `run_callbacks'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:63:in `enqueue'
/usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:30:in `perform_later'
/app/clock.rb:22:in `block in <module:Clockwork>'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:61:in `execute'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:48:in `run'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:136:in `block in tick'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `each'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `tick'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:123:in `block (2 levels) in run_tick_loop'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `synchronize'
/usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `block in run_tick_loop'
/usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:435:in `block (2 levels) in thread_block_with_current_transaction'
/usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:357:in `capture_segment_error'
/usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:434:in `block in thread_block_with_current_transaction'
I, [2024-05-27T19:25:56.204850 #7]  INFO -- : Finished 'schedule:activate_subscriptions' duration_ms=204 error=#<Redis::TimeoutError: Waited 0.1 seconds>
/app/clock.rb:13:in `block in <module:Clockwork>': undefined local variable or method `e' for Clockwork:Module (NameError)

    Rails.logger.error(e.message)
                       ^
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:154:in `handle_error'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:65:in `rescue in execute'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:62:in `execute'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:48:in `run'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:136:in `block in tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `each'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:123:in `block (2 levels) in run_tick_loop'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `synchronize'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `block in run_tick_loop'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:435:in `block (2 levels) in thread_block_with_current_transaction'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:357:in `capture_segment_error'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:434:in `block in thread_block_with_current_transaction'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:140:in `block in fill_buffer': Waited 0.1 seconds (Redis::TimeoutError)
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `loop'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `fill_buffer'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:114:in `ensure_remaining'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:85:in `getbyte'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:113:in `parse'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:50:in `load'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection.rb:94:in `read'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/connection_mixin.rb:31:in `call'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:239:in `block (2 levels) in call_v'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/middlewares.rb:16:in `call'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:238:in `block in call_v'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:643:in `ensure_connected'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:237:in `call_v'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/client.rb:73:in `call_v'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:167:in `block in send_command'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `synchronize'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `send_command'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:110:in `_eval'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:97:in `evalsha'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block (2 levels) in lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:152:in `with'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block in lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:208:in `recover_from_script_flush'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:170:in `lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block (2 levels) in lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `select'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block in lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:311:in `timed'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:257:in `lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:232:in `block in try_lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `times'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `try_lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:69:in `lock'
        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:24:in `lock'        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:59:in `before_enqueue'
        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/active_job_patch.rb:50:in `block (2 levels) in <module:ActiveJobPatch>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `block in make_lambda'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:199:in `block (2 levels) in halting'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:687:in `block (2 levels) in default_terminator'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `catch'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `block in default_terminator'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:200:in `block in halting'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `block in invoke_before'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `each'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `invoke_before'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:116:in `block in run_callbacks'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:25:in `block in instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `block in instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `instrument'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:35:in `instrument'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:9:in `block (2 levels) in <module:Instrumentation>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
        from /usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `block in tag_logger'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `block in tagged'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:37:in `tagged'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `tagged'
        from /usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `tag_logger'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:138:in `run_callbacks'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:63:in `enqueue'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:30:in `perform_later'
        from /app/clock.rb:22:in `block in <module:Clockwork>'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:61:in `execute'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:48:in `run'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:136:in `block in tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `each'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:123:in `block (2 levels) in run_tick_loop'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `synchronize'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `block in run_tick_loop'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:435:in `block (2 levels) in thread_block_with_current_transaction'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:357:in `capture_segment_error'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:434:in `block in thread_block_with_current_transaction'
/usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:140:in `block in fill_buffer': Waited 0.1 seconds (RedisClient::ReadTimeoutError)
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `loop'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:122:in `fill_buffer'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:114:in `ensure_remaining'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/buffered_io.rb:85:in `getbyte'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:113:in `parse'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection/resp3.rb:50:in `load'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/ruby_connection.rb:94:in `read'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/connection_mixin.rb:31:in `call'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:239:in `block (2 levels) in call_v'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client/middlewares.rb:16:in `call'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:238:in `block in call_v'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:643:in `ensure_connected'
        from /usr/local/bundle/gems/redis-client-0.17.0/lib/redis_client.rb:237:in `call_v'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/client.rb:73:in `call_v'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:167:in `block in send_command'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `synchronize'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis.rb:166:in `send_command'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:110:in `_eval'
        from /usr/local/bundle/gems/redis-5.0.6/lib/redis/commands/scripting.rb:97:in `evalsha'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block (2 levels) in lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:152:in `with'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:171:in `block in lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:208:in `recover_from_script_flush'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:170:in `lock'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block (2 levels) in lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `select'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:258:in `block in lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:311:in `timed'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:257:in `lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:232:in `block in try_lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `times'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:228:in `try_lock_instances'
        from /usr/local/bundle/gems/redlock-1.3.2/lib/redlock/client.rb:69:in `lock'
        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:24:in `lock'        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/strategies/base.rb:59:in `before_enqueue'
        from /usr/local/bundle/gems/activejob-uniqueness-0.2.5/lib/active_job/uniqueness/active_job_patch.rb:50:in `block (2 levels) in <module:ActiveJobPatch>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:467:in `block in make_lambda'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:199:in `block (2 levels) in halting'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:687:in `block (2 levels) in default_terminator'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `catch'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:686:in `block in default_terminator'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:200:in `block in halting'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `block in invoke_before'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `each'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:595:in `invoke_before'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:116:in `block in run_callbacks'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:25:in `block in instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `block in instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications/instrumenter.rb:24:in `instrument'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/notifications.rb:206:in `instrument'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:35:in `instrument'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/instrumentation.rb:9:in `block (2 levels) in <module:Instrumentation>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
        from /usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `block in tag_logger'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `block in tagged'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:37:in `tagged'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/tagged_logging.rb:99:in `tagged'
        from /usr/local/bundle/gems/activejob-traceable-0.4.2/lib/activejob/traceable/logging_patch.rb:17:in `tag_logger'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `instance_exec'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
        from /usr/local/bundle/gems/activesupport-7.0.8.1/lib/active_support/callbacks.rb:138:in `run_callbacks'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:63:in `enqueue'
        from /usr/local/bundle/gems/activejob-7.0.8.1/lib/active_job/enqueuing.rb:30:in `perform_later'
        from /app/clock.rb:22:in `block in <module:Clockwork>'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:61:in `execute'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/event.rb:48:in `run'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:136:in `block in tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `each'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:134:in `tick'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:123:in `block (2 levels) in run_tick_loop'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `synchronize'
        from /usr/local/bundle/gems/clockwork-3.0.2/lib/clockwork/manager.rb:121:in `block in run_tick_loop'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:435:in `block (2 levels) in thread_block_with_current_transaction'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:357:in `capture_segment_error'
        from /usr/local/bundle/gems/newrelic_rpm-9.5.0/lib/new_relic/agent/tracer.rb:434:in `block in thread_block_with_current_transaction'

After this stack trace, no further logging occurs. The clock container has died. However:

Name:             lago-clock-6758494485-4tqdw
Namespace:        xxx
Priority:         0
Service Account:  lago-serviceaccount
Node:             appmana-026/10.2.0.37
Start Time:       Fri, 24 May 2024 13:10:38 -0700
Labels:           io.lago.service=lago-clock
                  pod-template-hash=6758494485
Annotations:      cni.projectcalico.org/containerID: 169cc8c4bb1548aa3a33d93700f01d62152bff3d5d9efc38e87d958dce2ffbda
                  cni.projectcalico.org/podIP: 10.3.148.231/32
                  cni.projectcalico.org/podIPs: 10.3.148.231/32
Status:           Running
IP:               10.3.148.231
IPs:
  IP:           10.3.148.231
Controlled By:  ReplicaSet/lago-clock-6758494485
Init Containers:
  wait-for-redis:
    Container ID:  containerd://2126eacf3e025261fb658f52590ffac87266e955bbf88ccb1f1518735d6ed4ac
    Image:         docker.io/bitnami/kubectl:1.26
    Image ID:      docker.io/bitnami/kubectl@sha256:16255192d9659d1c4d0d3e3f7c562abf1934d6ea142bc08d99ce9189baabb438
    Port:          <none>
    Host Port:     <none>
    Args:
      wait
      pod/lago-redis-master-0
      --for=condition=ready
      --timeout=180s
    State:          Terminated
      Reason:       Completed
      Exit Code:    0
      Started:      Fri, 24 May 2024 13:10:44 -0700
      Finished:     Fri, 24 May 2024 13:10:44 -0700
    Ready:          True
    Restart Count:  0
    Environment:    <none>
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from kube-api-access-ffgsz (ro)
Containers:
  lago-clock:
    Container ID:  containerd://be3d07bb9f281fe6653f503ec5dffd2dd959a1714abe8ab747332d347c6979cf
    Image:         getlago/api:v1.2.1
    Image ID:      docker.io/getlago/api@sha256:c9dfe422a673640baea681df96848b671403e3221460e9c525b19784b2309ab2
    Port:          <none>
    Host Port:     <none>
    Args:
      ./scripts/start.clock.sh
    State:          Running
      Started:      Fri, 24 May 2024 13:10:52 -0700
    Ready:          True
    Restart Count:  0
    Requests:
      cpu:     100m
      memory:  256Mi
    Environment:
      RAILS_ENV:                       production
      DATABASE_URL:                    <set to the key 'databaseUrl' in secret 'lago-secrets'>  Optional: false
      REDIS_URL:                       <set to the key 'redisUrl' in secret 'lago-secrets'>     Optional: false
      RAILS_LOG_TO_STDOUT:             true
      LAGO_RSA_PRIVATE_KEY:            <set to the key 'rsaPrivateKey' in secret 'lago-secrets'>                Optional: false
      SECRET_KEY_BASE:                 <set to the key 'secretKeyBase' in secret 'lago-secrets'>                Optional: false
      ENCRYPTION_DETERMINISTIC_KEY:    <set to the key 'encryptionDeterministicKey' in secret 'lago-secrets'>   Optional: false
      ENCRYPTION_KEY_DERIVATION_SALT:  <set to the key 'encryptionKeyDerivationSalt' in secret 'lago-secrets'>  Optional: false
      ENCRYPTION_PRIMARY_KEY:          <set to the key 'encryptionPrimaryKey' in secret 'lago-secrets'>         Optional: false
      LAGO_LOG_LEVEL:                  info
    Mounts:
      /var/run/secrets/kubernetes.io/serviceaccount from kube-api-access-ffgsz (ro)
Conditions:
  Type              Status
  Initialized       True
  Ready             True
  ContainersReady   True
  PodScheduled      True
Volumes:
  kube-api-access-ffgsz:
    Type:                    Projected (a volume that contains injected data from multiple sources)
    TokenExpirationSeconds:  3607
    ConfigMapName:           kube-root-ca.crt
    ConfigMapOptional:       <nil>
    DownwardAPI:             true
QoS Class:                   Burstable
Node-Selectors:              kubernetes.io/os=linux
Tolerations:                 node.kubernetes.io/not-ready:NoExecute op=Exists for 300s
                             node.kubernetes.io/unreachable:NoExecute op=Exists for 300s
Events:                      <none>

Observe the pod is healthy.

To Reproduce Use the helm chart for 3 days. A transient redis issue will occur. Then clock will not recover from this transient issue.

Expected behavior clock should work in these scenarios.

Support 1.2.1

vincent-pochet commented 5 months ago

This issue has been fixed with https://github.com/getlago/lago-api/pull/2161

The fix will be part of the next release