# Locking issues in sidekiq jobs? **URL:** https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287 **Category:** Support **Created:** [2017年九月3日 13:49 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287 "2017-09-03T13:49:34Z") **Posts on this page:** 10 **Page:** 1
### Author: ![darix](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/darix/32/114280_2.png) [@darix](https://meta.discourse.org/u/darix) #### Post date: [2017年九月3日 13:49 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/1 "2017-09-03T13:49:34Z")
twice already we had cases where sidekiq was doing 100% cpu load if we strace the 2 processes shown maxing out the cpus we get: ```plaintext [pid 17688] futex(0x1e9b6e4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1e9b6e0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b718, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b71c, FUTEX_WAIT_PRIVATE, 759265, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 17688] futex(0x1e9b6e4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1e9b6e0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b718, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b71c, FUTEX_WAIT_PRIVATE, 759267, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 17688] sched_yield() = 0 [pid 17688] futex(0x1e9b6e4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1e9b6e0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b718, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b71c, FUTEX_WAIT_PRIVATE, 759269, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 17688] futex(0x1e9b6e4, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1e9b6e0, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b718, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b71c, FUTEX_WAIT_PRIVATE, 759271, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 17688] write(6, "!", 1) = 1 [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b6e0, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 17688] futex(0x1e9b6e4, FUTEX_WAIT_PRIVATE, 2478513, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 17688] futex(0x1e9b6b0, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 17688] sched_yield() = 0 ``` Any advice how to debug the issue? running: discourse-1.9.0.beta8~git1.3bdade8970 ---
### Author: ![darix](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/darix/32/114280_2.png) [@darix](https://meta.discourse.org/u/darix) #### Post date: [2017年九月3日 14:05 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/2 "2017-09-03T14:05:29Z")
a few updates 1. it didnt show any busy jobs while we saw the high cpu usage. 2. Jobs::PullHotlinkedImages was the only job scheduled when we checked why the cpu usage was so high ---
### Author: ![RGJ](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/rgj/32/523185_2.png) [@RGJ](https://meta.discourse.org/u/RGJ) #### Post date: [2019年一月2日 17:06 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/3 "2019-01-02T17:06:23Z")
Were you ever able to pinpoint this issue? We’re seeing the exact same thing on one server. Sidekiq goes to 90% CPU and the only way to get it back to normal is to restart it. It then stays low for a day or so and then it gets stuck at 90% again. `ps -T -p ` says this is happening in `manager.rb:27` which is here > There are no scheduled jobs in Sidekiq. ---
### Author: ![sam](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/sam/32/102149_2.png) [@sam](https://meta.discourse.org/u/sam) #### Post date: [2019年一月2日 19:45 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/4 "2019-01-02T19:45:05Z")
Use rbtrace to get a better back trace > **[Debugging 100% CPU usage in production Ruby on Rails systems](https://samsaffron.com/archive/2018/01/18/my-production-ruby-on-rails-cpu-is-at-100-now-what)** > > Sam's Spot - Sam saffron's web log ---
### Author: ![codinghorror](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/codinghorror/32/110067_2.png) [@codinghorror](https://meta.discourse.org/u/codinghorror) #### Post date: [2019年一月2日 21:31 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/5 "2019-01-02T21:31:32Z")
I believe it is on @david’s lower-priority list to have better logging of Sidekiq jobs? I am not sure where that is though. ---
### Author: ![david](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/david/32/157490_2.png) [@david](https://meta.discourse.org/u/david) #### Post date: [2019年一月2日 21:44 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/6 "2019-01-02T21:44:48Z")
The plan is to add additional logging to track sidekiq job duration, and various metrics such as DB time and Redis time. We’ll also regularly log “currently running jobs” on a regular basis, to help track things down in the event of a crash. I think it should be ready in 2-3 weeks time. ---
### Author: ![RGJ](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/rgj/32/523185_2.png) [@RGJ](https://meta.discourse.org/u/RGJ) #### Post date: [2019年一月3日 16:12 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/7 "2019-01-03T16:12:30Z")
Ok, this is what I got. I was hoping to spot the culprit more easily but maybe @sam does know better how to interpret these results… ``` ================================== Mode: cpu(1000) Samples: 7994 (0.32% miss rate) GC: 10 (0.13%) ================================== TOTAL (pct) SAMPLES (pct) FRAME 3301 (41.3%) 3300 (41.3%) ActiveModel::LazyAttributeHash#[] 2123 (26.6%) 2123 (26.6%) ActiveRecord::ConnectionAdapters::TransactionState#finalized? 897 (11.2%) 897 (11.2%) ActiveRecord::AttributeMethods::PrimaryKey::ClassMethods#primary_key 787 (9.8%) 786 (9.8%) ActiveModel::Attribute#value 7647 (95.7%) 118 (1.5%) ActiveRecord::AttributeMethods::PrimaryKey#id 3414 (42.7%) 113 (1.4%) ActiveModel::AttributeSet#[] 4400 (55.0%) 104 (1.3%) ActiveRecord::AttributeMethods::Read#_read_attribute 4296 (53.7%) 96 (1.2%) ActiveModel::AttributeSet#fetch_value 2210 (27.6%) 87 (1.1%) ActiveRecord::Transactions#update_attributes_from_transaction_state 55 (0.7%) 55 (0.7%) Nokogiri::XML::Document#decorate 7697 (96.3%) 51 (0.6%) ActiveRecord::Core#== 2234 (27.9%) 24 (0.3%) ActiveRecord::Transactions#sync_with_transaction_state 13 (0.2%) 13 (0.2%) ActionView::PathResolver#find_template_paths 12 (0.2%) 12 (0.2%) PG::Connection#async_exec 11 (0.1%) 11 (0.1%) Nokogiri::XML::XPathContext#register_namespaces 10 (0.1%) 10 (0.1%) (garbage collection) 8 (0.1%) 8 (0.1%) OpenSSL::Buffering#do_write 5 (0.1%) 5 (0.1%) Concurrent::Collection::NonConcurrentMapBackend#get_or_default 5 (0.1%) 5 (0.1%) Concurrent::Collection::NonConcurrentMapBackend#[] 4 (0.1%) 4 (0.1%) Arel::Collectors::PlainString#<< 4 (0.1%) 4 (0.1%) ActiveRecord::Relation#initialize_copy 4 (0.1%) 4 (0.1%) ActiveSupport::PerThreadRegistry#instance 3 (0.0%) 3 (0.0%) #.parse 3 (0.0%) 3 (0.0%) OpenSSL::SSL::SSLContext#initialize 3 (0.0%) 3 (0.0%) #.blank? 3 (0.0%) 3 (0.0%) Net::Protocol#ssl_socket_connect 4 (0.1%) 3 (0.0%) ActiveModel::Type::Helpers::Numeric#cast 4 (0.1%) 3 (0.0%) Nokogiri::XML::Node#write_to 4 (0.1%) 3 (0.0%) #.reap_connections 4 (0.1%) 3 (0.0%) MiniRacer::Context#timeout ``` ---
### Author: ![RGJ](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/rgj/32/523185_2.png) [@RGJ](https://meta.discourse.org/u/RGJ) #### Post date: [2019年八月26日 16:02 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/8 "2019-08-26T16:02:41Z")
这个问题曾一度消失，但随后又出现了。现在，我们终于找到了问题的根源。 有一个数据库查询被一个定期执行的用户清理任务触发后一直挂起，无法完成。该查询在运行半小时后被强制终止并重新启动。当我们手动执行该任务时，问题便消失了。 ---
### Author: ![system](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/system/32/443519_2.png) [@system](https://meta.discourse.org/u/system) #### Post date: [2023年三月15日 20:39 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/9 "2023-03-15T20:39:11Z")
---
### Author: ![Stephen](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/stephen/32/95011_2.png) [@Stephen](https://meta.discourse.org/u/Stephen) #### Post date: [2023年三月15日 20:48 UTC](https://meta.discourse.org/t/locking-issues-in-sidekiq-jobs/69287/10 "2023-03-15T20:48:44Z")