Infos:
- Used Zammad version: 5.2.0-alpha-1654086634.2fefa6f3.bullseye
- Used Zammad installation type: (source, package, docker-compose, …) package
- Operating system: Debian Bullseye
- Browser + version: Chrome latest
Expected behavior: low CPU use
Actual behavior: High CPU use
Steps to reproduce the behavior: just installed with apt-get upgrade
Since upgrading to 5.2.0-alpha-1654086634.2fefa6f3.bullseye I’ve seen a high CPU usage by this process:
1867705 ? Rs 0:00 script/background-services.rb start APP_RUNNER_CLI=systemctl RAILS_LOG_TO_STDOUT= APP_USER=zammad APP_GROUP=zammad APP_SAFE_NAME=zammad
Zammad log is filled by a repeated action occurring every 6 seconds:
I, [2022-06-01T15:51:37.795552 #1350169-7160] INFO -- : Using Zammad's file store as Rails cache store.
I, [2022-06-01T15:51:37.795718 #1350169-7160] INFO -- : Using File as web socket session store.
I, [2022-06-01T15:51:38.195765 #1350169-7160] INFO -- : Setting.set('product_logo', "27ad73322e96990eb351803af90d2c44.png")
I, [2022-06-01T15:51:40.081320 #1350169-7160] INFO -- : Setting.set('models_searchable', ["Chat::Session", "KnowledgeBase::Answer::Translation", "Organization", "Ticket", "User"])
I, [2022-06-01T15:51:43.472829 #1350230-7160] INFO -- : Using Zammad's file store as Rails cache store.
I, [2022-06-01T15:51:43.472968 #1350230-7160] INFO -- : Using File as web socket session store.
I, [2022-06-01T15:51:43.869807 #1350230-7160] INFO -- : Setting.set('product_logo', "27ad73322e96990eb351803af90d2c44.png")
I, [2022-06-01T15:51:45.798615 #1350230-7160] INFO -- : Setting.set('models_searchable', ["Chat::Session", "KnowledgeBase::Answer::Translation", "Organization", "Ticket", "User"])
This process is using up to 100% CPU. Log message was not present before the last apt upgrade and started right after the upgrade.
I had to shutdown Zammad because the high cpu usage drained all the AWS burstable capacity.
Any idea on how to solve this issue? Thanks!
Hi @admin-gbm
This update contains script/scheduler.rb renaming to script/background-services.rb.
Do you have any custom changes that may cause it to die? It looks like the script may be constantly restarting.
This script may take a lot of CPU during boot up but then use resources according to load.
Is this a fresh installation? Upgrade of an existing system?
Friendly side note: Using development versions of Zammad for production is not suggested. You’re proceeding on your own danger here.
Looks like a bug.
Syslog actually hints for the reason:
Jun 2 15:34:20 zammad systemd[1]: Started zammad-worker-1.service.
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: bundler: failed to load command: script/background-services.rb (script/background-services.rb)
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: /opt/zammad/lib/background_services/cli.rb:4:in `<class:BackgroundServices>': uninitialized constant Thor (NameError)
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/lib/background_services/cli.rb:3:in `<main>'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bootsnap-1.12.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bootsnap-1.12.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27:in `require'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from script/background-services.rb:16:in `<top (required)>'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:58:in `load'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:58:in `kernel_load'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:23:in `run'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:479:in `exec'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:31:in `dispatch'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:25:in `start'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/exe/bundle:49:in `block in <top (required)>'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/friendly_errors.rb:103:in `with_friendly_errors'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/exe/bundle:37:in `<top (required)>'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/bin/bundle:121:in `load'
Jun 2 15:34:23 zammad zammad-worker-1.service[14318]: #011from /opt/zammad/bin/bundle:121:in `<main>'
Jun 2 15:34:23 zammad systemd[1]: zammad-worker-1.service: Main process exited, code=exited, status=1/FAILURE
Jun 2 15:34:23 zammad systemd[1]: zammad-worker-1.service: Failed with result 'exit-code'.
Jun 2 15:34:23 zammad systemd[1]: zammad-worker-1.service: Service RestartSec=100ms expired, scheduling restart.
Jun 2 15:34:23 zammad systemd[1]: zammad-worker-1.service: Scheduled restart job, restart counter is at 23.
Could you please create an issue? Thank you.
Looks like this is exactly what’s happening. It’s not a fresh installation, it’s a test server I keep updated via apt and it gets the dev Zammad’s updates nearly daily.
I did not make any custom changes, or at least I do not remeber as it was installed more than two years ago. There must be something in that renaming causing script/background-services.rb to crash. It’s been working fine until yesterday’s update. I just tried today’s update (5.2.0-alpha-1654107415.b3639fb8.bullseye) but it did not solve the issue. Too bad I do not know Ruby so I cannot help. I will monitor the next updates for a solution, in case I’ll start a new fresh one. Thanks for your help.
I know I know, I been there (in the dangerous zone) sooo many times! 
Fortunately it’s a personal test server, it helps me prevent the nasty bugs reach the clients. Thanks anyway for the advice, it’s always appreciated!
I have the same syslog error:
Jun 2 12:06:24 systemd[1]: Started zammad.service.
Jun 2 12:06:24 systemd[1]: Started zammad-web.service.
Jun 2 12:06:24 systemd[1]: Started zammad-web-1.service.
Jun 2 12:06:24 systemd[1]: Started zammad-websocket.service.
Jun 2 12:06:24 systemd[1]: Started zammad-websocket-1.service.
Jun 2 12:06:24 systemd[1]: Started zammad-worker.service.
Jun 2 12:06:24 systemd[1]: Started zammad-worker-1.service.
Jun 2 12:06:27 zammad-web-1.service[1864364]: => Booting Puma
Jun 2 12:06:27 zammad-web-1.service[1864364]: => Rails 6.1.6 application starting in production
Jun 2 12:06:27 zammad-web-1.service[1864364]: => Run `bin/rails server --help` for more startup options
Jun 2 12:06:32 zammad-web-1.service[1864364]: Puma starting in single mode...
Jun 2 12:06:32 zammad-web-1.service[1864364]: * Version 4.3.12 (ruby 3.0.4-p208), codename: Mysterious Traveller
Jun 2 12:06:32 zammad-web-1.service[1864364]: * Min threads: 5, max threads: 30
Jun 2 12:06:32 zammad-web-1.service[1864364]: * Environment: production
Jun 2 12:06:32 zammad-web-1.service[1864364]: * Listening on tcp://127.0.0.1:3000
Jun 2 12:06:32 zammad-web-1.service[1864364]: Use Ctrl-C to stop
Jun 2 12:06:33 zammad-worker-1.service[1864369]: bundler: failed to load command: script/background-services.rb (script/background-services.rb)
Jun 2 12:06:33 zammad-worker-1.service[1864369]: /opt/zammad/lib/background_services/cli.rb:4:in `<class:BackgroundServices>': uninitialized constant Thor (NameError)
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/lib/background_services/cli.rb:3:in `<main>'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bootsnap-1.12.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bootsnap-1.12.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/zeitwerk-2.5.4/lib/zeitwerk/kernel.rb:27:in `require'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from script/background-services.rb:16:in `<top (required)>'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:58:in `load'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:58:in `kernel_load'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli/exec.rb:23:in `run'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:479:in `exec'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor.rb:392:in `dispatch'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:31:in `dispatch'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/vendor/thor/lib/thor/base.rb:485:in `start'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/cli.rb:25:in `start'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/exe/bundle:49:in `block in <top (required)>'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/lib/bundler/friendly_errors.rb:103:in `with_friendly_errors'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/vendor/bundle/ruby/3.0.0/gems/bundler-2.2.33/exe/bundle:37:in `<top (required)>'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/bin/bundle:121:in `load'
Jun 2 12:06:33 zammad-worker-1.service[1864369]: #011from /opt/zammad/bin/bundle:121:in `<main>'
Jun 2 12:06:33 systemd[1]: zammad-worker-1.service: Main process exited, code=exited, status=1/FAILURE
Jun 2 12:06:33 systemd[1]: zammad-worker-1.service: Failed with result 'exit-code'.
Jun 2 12:06:33 systemd[1]: zammad-worker-1.service: Consumed 5.228s CPU time.
I’m opening an issue on Github. Thanks.
The fix is now merged in develop branch and will be available as alpha package soon.
Thank you @admin-gbm for noticing this!