Bug #12334
closed
dynflow_executor is constantly spawning processes and consumes a lot of cpu
Description
Here is top part for dynaflow:
5874 foreman 20 0 1934M 287M 7180 S 84.6 1.8 2:47.15 dynflow_executor
7259 foreman 20 0 1934M 287M 7180 S 19.4 1.8 0:07.65 dynflow_executor
8104 foreman 20 0 1934M 287M 7180 S 18.0 1.8 0:06.83 dynflow_executor
7258 foreman 20 0 1934M 287M 7180 S 8.0 1.8 0:06.92 dynflow_executorTracing the top pid show lines like this:
[pid 7265] futex(0x1cd3f30, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 7263] futex(0x1cd3f30, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 8242] futex(0x1cd3f64, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1cd3f60, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...>
[pid 8102] futex(0x1cd3f60, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 7265] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 7263] <... futex resumed> ) = 0
[pid 14596] <... futex resumed> ) = 0
[pid 8242] <... futex resumed> ) = 1
[pid 8102] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 7265] futex(0x1cd3f30, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 7263] futex(0x1cd3f9c, FUTEX_WAIT_PRIVATE, 3745, NULL <unfinished ...>
[pid 14596] futex(0x1cd3f30, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 8242] futex(0x1cd3f30, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 8102] futex(0x1cd3f60, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 7265] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 14596] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
[pid 8242] <... futex resumed> ) = 0
[pid 8102] <... futex resumed> ) = 0
[pid 7265] futex(0x1cd3f30, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 14596] futex(0x1cd3f30, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid 8242] futex(0x7efe24020f9c, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...>
[pid 8102] futex(0x1cd3f60, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid 7265] <... futex resumed> ) = 0
[pid 14596] <... futex resumed> ) = 0
[pid 7260] <... select resumed> ) = 1 (in [12])
[pid 7260] futex(0x1cd3f30, FUTEX_WAIT_PRIVATE, 2, NULL^CProcess 5874 detached
With the -c parameter:
[root@puppet sdt_user]# strace f -p 5874 -c ----------- ----------- --------- --------- ----------------
Process 5874 attached with 17 threads
Process 15411 attached
Process 15412 attached
Process 15413 attached
Process 15414 attached
Process 15415 attached
........
........
% time seconds usecs/call calls errors syscall
-----
88.59 1.649508 249 6624 691 futex
8.46 0.157599 834 189 select
2.32 0.043144 1198 36 ppoll
0.28 0.005283 93 57 poll
0.10 0.001918 50 38 connect
0.07 0.001296 6 214 sendto
0.05 0.001009 2 637 stat
0.03 0.000480 1 583 346 recvfrom
0.02 0.000347 1 458 53 read
0.02 0.000314 4 84 write
0.01 0.000173 5 38 socket
0.01 0.000155 8 19 mmap
0.01 0.000151 4 38 clone
0.01 0.000137 7 19 sendmmsg
0.01 0.000136 4 36 madvise
0.01 0.000120 3 38 set_robust_list
0.00 0.000063 3 19 munmap
0.00 0.000045 1 76 fstat
0.00 0.000033 1 55 close
0.00 0.000028 1 38 sched_getaffinity
0.00 0.000024 1 19 open
0.00 0.000021 1 38 ioctl
0.00 0.000011 0 38 sigaltstack
0.00 0.000010 0 38 fcntl
0.00 0.000002 0 34 rt_sigprocmask
------ ----------- ----------- --------- --------- ----------------
100.00 1.862007 9463 1090 total
Updated by Anonymous over 8 years ago
Which OS/dstro? Which OS/distro, dynflow and foreman-tasks versions are being used?
Updated by cristian falcas over 8 years ago
This is an OracleLinux 7 (sorry about that)
Packages installed:
foreman-1.9.2-1.el7.noarch
foreman-compute-1.9.2-1.el7.noarch
foreman-debug-1.9.2-1.el7.noarch
foreman-ec2-1.9.2-1.el7.noarch
foreman-gce-1.9.2-1.el7.noarch
foreman-libvirt-1.9.2-1.el7.noarch
foreman-ovirt-1.9.2-1.el7.noarch
foreman-postgresql-1.9.2-1.el7.noarch
foreman-proxy-1.9.2-1.el7.noarch
foreman-selinux-1.9.2-1.el7.noarch
foreman-vmware-1.9.2-1.el7.noarch
ruby193-rubygem-foreman_abrt-0.0.6-2.el7.noarch
ruby193-rubygem-foreman_bootdisk-6.0.0-1.el7.noarch
ruby193-rubygem-foreman_docker-1.4.1-1.fm1_9.el7.noarch
ruby193-rubygem-foreman_gutterball-0.0.1-1.201507061443gitb9974c7.git.0.64e9626.el7.noarch
ruby193-rubygem-foreman_hooks-0.3.8-1.el7.noarch
ruby193-rubygem-foreman_openscap-0.4.3-1.fm1_9.el7.noarch
ruby193-rubygem-foreman-tasks-0.7.6-1.fm1_9.el7.noarch
ruby193-rubygem-puppetdb_foreman-0.1.2-1.el7.noarch
rubygem-foreman_scap_client-0.1.1-1.el7.noarch
rubygem-hammer_cli_foreman-0.3.0-1.el7.noarch
rubygem-hammer_cli_foreman_bootdisk-0.1.3-1.el7.noarch
rubygem-hammer_cli_foreman_docker-0.0.3-2.el7.noarch
rubygem-hammer_cli_foreman_tasks-0.0.7-1.el7.noarch
Updated by cristian falcas over 8 years ago
ruby193-rubygem-dynflow-0.8.7-1.el7.noarch
Updated by Anonymous over 8 years ago
I don't think this will be the same bug, but the trace reminds me of a problem with -tasks/dynflow that got fixed with te update of the daemon gem to 1.2.2, could you please paste the output of rpm -qa|grep daemon?
Updated by cristian falcas over 8 years ago
I think this is what you want:
ruby193-rubygem-daemons-1.2.2-1.el7.noarch
Updated by Anonymous over 8 years ago
yes, that version did not expose that bug for me anymore, so over to the dynflow/tasks experts... :)
Updated by Ivan Necas over 8 years ago
Could you look at
/var/log/foreman/dynflow_executor.output
Also, I don't see any plugin that would actively use the foreman-tasks/dynflow in your setup. How did you end up having that installed?
Updated by cristian falcas over 8 years ago
I think that ruby193-rubygem-foreman-tasks should use dynflow_executor.
Anyway, it looks like after a while the process went back to normal.
I can't reproduce this anymore.
Sorry for this.