Murano-engine utilizes 100% of CPU

Bug #1504135 reported by Anastasia Kuznetsova
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Murano
Invalid
High
Unassigned
Mitaka
Invalid
High
Unassigned

Bug Description

During Murano performance testing was discovered that starting from 22-25 concurrently (it depends on how the load will be distributed among controllers) environment deployments 10-20% deployments failed with error during usage of heat, neutron or keystone clients as Haproxy closes connection with 408 error:

<134>Sep 28 16:40:38 node-126 haproxy[32680]: 172.16.46.57:42623 [28/Sep/2015:16:40:18.037] heat-api heat-api/<NOSRV> -1/-1/-1/-1/20001 408 212 - - cR-- 2/1/0/0/3 0/0 "<BADREQ>"

 where
            c : the client-side timeout expired while waiting for the client to
            send or receive data.
            R : the proxy was waiting for a complete, valid REQUEST from the client
            (HTTP mode only). Nothing was sent to any server.

2015-09-28 16:40:48.412 13999 DEBUG murano.dsl.executor [-] 604d1bff76404751a7e114876fc2203b: End execution: io.murano.system.HeatStack.updateTemplate (-1777664545764330947) with exception [heatclient.exc.HTTPException]: ERROR: <html><body><h1>408 Request Time-out</h1>
Your browser didn't send a complete request in time.
</body></html>
 _invoke_method_implementation /usr/lib/python2.7/dist-packages/murano/dsl/executor.py:156

Apparently, it happens as Murano-engine uses green theads and utilizes only one CPU of controller. And starting from 22-25 concurrently deployments utilize 100% of CPU.

Additionaly about the same percent of failures is caused by Socket closed/Broken pipe errors, apparently also as Murano-engine comes to the state of lack of CPU resources to support heartbeats.

processor : 5
vendor_id : GenuineIntel
cpu family : 6
model : 62
model name : Intel(R) Xeon(R) CPU E5-2620 v2 @ 2.10GHz
stepping : 4
microcode : 0x424
cpu MHz : 1200.000
cache size : 15360 KB
physical id : 0
siblings : 12
core id : 5
cpu cores : 6
apicid : 10
initial apicid : 10
fpu : yes
fpu_exception : yes
cpuid level : 13
wp : yes
flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm ida arat epb xsaveopt pln pts dtherm tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms
bogomips : 4200.37
clflush size : 64
cache_alignment : 64
address sizes : 46 bits physical, 48 bits virtual
power management:

Going to check a possible workaround: to run 1 additional murano-engine on each of controllers. Will add comment with results.

Changed in murano:
milestone: none → mitaka-1
importance: Undecided → High
status: New → Triaged
Revision history for this message
Ekaterina Chernova (efedorova) wrote :
Changed in murano:
status: Triaged → Confirmed
Revision history for this message
Viktoria Efimova (vefimova) wrote :

Adding additional engine didn't decrease the amount of failures nor CPU utilization. Both engine at specific time point reached 100% CPU utilization.

The distribution of operations among engines is steady:
http://paste.openstack.org/show/476025/

From atop logs it is seen that 100% CPU utilization by one of the engine is reached from 00:04:41 to 00:21:01.
Checking logs for this time period shows that murano is probably very busy as the time between deployment task was started and tempate was sent to heat is more than 10 minutes, whereas in normal case this time period is 2-10 secs.
Start task to deploy:
2015-10-09 00:04:03.730 2169 INFO murano.common.engine [-] Starting processing task: {"action": {"args": {}, "method": "deploy", "object_id": "03f7f529806a418d95cdb92693e969f0"}, "tenant_id": "bc9cc5225de9488493c27e74b192f4f5", "model": {"Attributes": [], "Objects": {"defaultNetworks": {"environment": {"name": "rally_VYJiOzDGNy-network", "?": {"type": "io.murano.resources.NeutronNetwork", "id": "0027648865c040028e0a2c7f85285bd1"}}, "flat": null}, "name": "rally_VYJiOzDGNy", "?": {"type": "io.murano.Environment", "id": "03f7f529806a418d95cdb92693e969f0"}, "applications": [{"name": "my.domain-4QAZNAtuBwKbgwrz", "adminPassword": "*** SANITIZED ***", "adminAccountName": "Administrator", "primaryController": {"host": {"availabilityZone": "nova", "name": "murano-1", "securityGroupName": null, "assignFloatingIp": false, "adminPassword": "*** SANITIZED ***", "keyname": null, "floatingIpAddress": null, "adminAccountName": "Administrator", "flavor": "m1.medium", "image": "Murano_windows_image", "?": {"type": "io.murano.apps.activeDirectory.Host", "id": "73d3827f-b15b-463e-8012-de3d15f54076"}}, "recoveryPassword": "*** SANITIZED ***", "?": {"type": "io.murano.apps.activeDirectory.PrimaryController", "id": "e67b587a-64a7-4a77-9849-345c916b1f62"}}, "secondaryControllers": [], "?": {"type": "io.murano.apps.activeDirectory.ActiveDirectory", "id": "2ac09a3b-aae2-4530-9e35-2bca474feb0b"}}]}}, "token": "*** SANITIZED ***", "id": "03f7f529806a418d95cdb92693e969f0"}

Sent template to heat
2015-10-09 00:14:25.617 2169 INFO murano.engine.system.heat_stack [-] Pushing: {'heat_template_version': '2013-05-23', 'description': 'This stack was generated by Murano for environment rally_VYJiOzDGNy (ID: 03f7f529806a418d95cdb92693e969f0)', 'resources': {}}

no longer affects: murano/liberty
tags: added: liberty-backport-potential
Revision history for this message
Ekaterina Chernova (efedorova) wrote :

Need more information about the environment, we could not reproduce it

no longer affects: murano/liberty
Changed in murano:
milestone: mitaka-1 → mitaka-2
Revision history for this message
Serg Melikyan (smelikyan) wrote :

We were unable to reproduce this bug anymore, closing as InComplete

Changed in murano:
milestone: mitaka-2 → mitaka-3
Changed in murano:
milestone: mitaka-3 → mitaka-rc1
Changed in murano:
milestone: mitaka-rc1 → newton-1
Revision history for this message
Valerii Kovalchuk (vakovalchuk) wrote :

Since the bug is not reproducable and there is no new information, setting status to Invalid

Changed in murano:
status: Incomplete → Invalid
Revision history for this message
Joon-ha, Park (junaa) wrote :

I'v used the murano on the version of Kilo, It's easily reproduced by on our environment. Is there any consideration about this bug?

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.