create_userrc.sh is sllllooww
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
devstack |
New
|
Undecided
|
Unassigned | ||
python-openstackclient |
New
|
Undecided
|
Unassigned |
Bug Description
I'm not sure this is a new thing, since log data does not go back that far, but we've been seeing occasional failures of the ironic job due to a slowdown in what devstack is doing between startings n-cpu and ir-api, see Bug #1441007. In looking through logs, it looks like the primary cause in the lag between starting n-cpu and ir-api is the create_userrc.sh script, specifically calls to 'openstack ec2 credentials create' + 'openstack ec2 credentials list', each command taking about 3 secs to complete:
2015-04-06 16:46:19.085 | + openstack ec2 credentials create --user 855dcf30897447d
2015-04-06 16:46:22.071 | +------
2015-04-06 16:46:22.071 | | Field | Value |
2015-04-06 16:46:22.071 | +------
2015-04-06 16:46:22.071 | | access | 588292339dcf49a
2015-04-06 16:46:22.071 | | project_id | 02678d546d56423
2015-04-06 16:46:22.071 | | secret | 2dba25517d00461
2015-04-06 16:46:22.071 | | trust_id | None |
2015-04-06 16:46:22.072 | | user_id | 855dcf30897447d
2015-04-06 16:46:22.072 | +------
2015-04-06 16:46:22.205 | ++ openstack ec2 credentials list --user 855dcf30897447d
2015-04-06 16:46:22.206 | ++ grep ' 02678d546d56423
2015-04-06 16:46:25.275 | + line='| 588292339dcf49a
2015-04-06 16:46:25.275 | + local ec2_access_key ec2_secret_key
2015-04-06 16:46:25.275 | + read ec2_access_key ec2_secret_key
2015-04-06 16:46:25.275 | ++ echo '|' 588292339dcf49a
2015-04-06 16:46:25.276 | ++ awk '{print $2 " " $4 }'
Between create and list, create_userrc.sh is calling 24 osc ec2 commands (at least for this specific job), sometimes burning almost 2 mins. The ironic issue can be worked around with a bump to its API retries, but there may be something else new going on here causing the slowdown.
Example log @ http://
possibly related to https:/ /bugs.launchpad .net/python- openstackclient /+bug/1431649