Not only does it do heavy queries, but it rebuilds the entire metadata set for every single request that is made to the metadata server. Horribly inefficient! I want to break the metadata code out into its own binary as well. I will be filing a blueprint to that affect soon. We definitely need some efficiency cleanup for the metadata server as well.
On Sep 15, 2011, at 11:26 AM, Scott Moser wrote:
> Public bug reported:
>
> $ time python -c 'import boto.utils; boto.utils.get_instance_metadata()'
>
> real 0m5.740s
> user 0m0.190s
> sys 0m0.110s
>
> I've not done a lot of digging on this, but I suspect that
> nova/api/ec2/cloud.py:get_metadata is doing some heavy queries.
>
> cloud-init does at least 2 separate hits of the metadata service on
> boot, this means we see something like this in cloud-init.log:
>
> 2011-09-15 18:17:53,844 - cloud-init[INFO]: cloud-init start running: Thu, 15 Sep 2011 18:17:53 +0000. up 6.01 seconds
> 2011-09-15 18:17:53,855 - __init__.py[DEBUG]: searching for data source in ['DataSourceNoCloudNet', 'DataSourceOVFNet', 'DataSourceEc2']
> 2011-09-15 18:17:53,989 - DataSourceEc2.py[DEBUG]: removed the following from metadata urls: ['http://instance-data:8773']
> 2011-09-15 18:17:53,989 - DataSourceEc2.py[DEBUG]: Searching the following metadata urls: ['http://169.254.169.254']
> 2011-09-15 18:17:54,350 - DataSourceEc2.py[DEBUG]: Using metadata source: 'http://169.254.169.254'
> 2011-09-15 18:18:00,027 - __init__.py[DEBUG]: found data source DataSourceEc2
> 2011-09-15 18:18:00,050 - cloud-init[DEBUG]: found data source: DataSourceEc2
>
>
> Note the 5 second time lapse between 'Using' and 'found'. Using just indicated there the port was open. found actually used data from it.
>
> ** Affects: nova
> Importance: Undecided
> Status: New
>
> --
> You received this bug notification because you are a member of Nova Bug
> Team, which is subscribed to OpenStack Compute (nova).
> https://bugs.launchpad.net/bugs/851159
>
> Title:
> ec2 metadata service is very slow
>
> Status in OpenStack Compute (Nova):
> New
>
> Bug description:
> $ time python -c 'import boto.utils;
> boto.utils.get_instance_metadata()'
>
> real 0m5.740s
> user 0m0.190s
> sys 0m0.110s
>
> I've not done a lot of digging on this, but I suspect that
> nova/api/ec2/cloud.py:get_metadata is doing some heavy queries.
>
> cloud-init does at least 2 separate hits of the metadata service on
> boot, this means we see something like this in cloud-init.log:
>
> 2011-09-15 18:17:53,844 - cloud-init[INFO]: cloud-init start running: Thu, 15 Sep 2011 18:17:53 +0000. up 6.01 seconds
> 2011-09-15 18:17:53,855 - __init__.py[DEBUG]: searching for data source in ['DataSourceNoCloudNet', 'DataSourceOVFNet', 'DataSourceEc2']
> 2011-09-15 18:17:53,989 - DataSourceEc2.py[DEBUG]: removed the following from metadata urls: ['http://instance-data:8773']
> 2011-09-15 18:17:53,989 - DataSourceEc2.py[DEBUG]: Searching the following metadata urls: ['http://169.254.169.254']
> 2011-09-15 18:17:54,350 - DataSourceEc2.py[DEBUG]: Using metadata source: 'http://169.254.169.254'
> 2011-09-15 18:18:00,027 - __init__.py[DEBUG]: found data source DataSourceEc2
> 2011-09-15 18:18:00,050 - cloud-init[DEBUG]: found data source: DataSourceEc2
>
>
> Note the 5 second time lapse between 'Using' and 'found'. Using just indicated there the port was open. found actually used data from it.
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/nova/+bug/851159/+subscriptions
Not only does it do heavy queries, but it rebuilds the entire metadata set for every single request that is made to the metadata server. Horribly inefficient! I want to break the metadata code out into its own binary as well. I will be filing a blueprint to that affect soon. We definitely need some efficiency cleanup for the metadata server as well.
On Sep 15, 2011, at 11:26 AM, Scott Moser wrote:
> Public bug reported: get_instance_ metadata( )' ec2/cloud. py:get_ metadata is doing some heavy queries. loudNet' , 'DataSourceOVFNet', 'DataSourceEc2'] py[DEBUG] : removed the following from metadata urls: ['http:// instance- data:8773'] py[DEBUG] : Searching the following metadata urls: ['http:// 169.254. 169.254'] py[DEBUG] : Using metadata source: 'http:// 169.254. 169.254' /bugs.launchpad .net/bugs/ 851159 get_instance_ metadata( )' ec2/cloud. py:get_ metadata is doing some heavy queries. loudNet' , 'DataSourceOVFNet', 'DataSourceEc2'] py[DEBUG] : removed the following from metadata urls: ['http:// instance- data:8773'] py[DEBUG] : Searching the following metadata urls: ['http:// 169.254. 169.254'] py[DEBUG] : Using metadata source: 'http:// 169.254. 169.254' /bugs.launchpad .net/nova/ +bug/851159/ +subscriptions
>
> $ time python -c 'import boto.utils; boto.utils.
>
> real 0m5.740s
> user 0m0.190s
> sys 0m0.110s
>
> I've not done a lot of digging on this, but I suspect that
> nova/api/
>
> cloud-init does at least 2 separate hits of the metadata service on
> boot, this means we see something like this in cloud-init.log:
>
> 2011-09-15 18:17:53,844 - cloud-init[INFO]: cloud-init start running: Thu, 15 Sep 2011 18:17:53 +0000. up 6.01 seconds
> 2011-09-15 18:17:53,855 - __init__.py[DEBUG]: searching for data source in ['DataSourceNoC
> 2011-09-15 18:17:53,989 - DataSourceEc2.
> 2011-09-15 18:17:53,989 - DataSourceEc2.
> 2011-09-15 18:17:54,350 - DataSourceEc2.
> 2011-09-15 18:18:00,027 - __init__.py[DEBUG]: found data source DataSourceEc2
> 2011-09-15 18:18:00,050 - cloud-init[DEBUG]: found data source: DataSourceEc2
>
>
> Note the 5 second time lapse between 'Using' and 'found'. Using just indicated there the port was open. found actually used data from it.
>
> ** Affects: nova
> Importance: Undecided
> Status: New
>
> --
> You received this bug notification because you are a member of Nova Bug
> Team, which is subscribed to OpenStack Compute (nova).
> https:/
>
> Title:
> ec2 metadata service is very slow
>
> Status in OpenStack Compute (Nova):
> New
>
> Bug description:
> $ time python -c 'import boto.utils;
> boto.utils.
>
> real 0m5.740s
> user 0m0.190s
> sys 0m0.110s
>
> I've not done a lot of digging on this, but I suspect that
> nova/api/
>
> cloud-init does at least 2 separate hits of the metadata service on
> boot, this means we see something like this in cloud-init.log:
>
> 2011-09-15 18:17:53,844 - cloud-init[INFO]: cloud-init start running: Thu, 15 Sep 2011 18:17:53 +0000. up 6.01 seconds
> 2011-09-15 18:17:53,855 - __init__.py[DEBUG]: searching for data source in ['DataSourceNoC
> 2011-09-15 18:17:53,989 - DataSourceEc2.
> 2011-09-15 18:17:53,989 - DataSourceEc2.
> 2011-09-15 18:17:54,350 - DataSourceEc2.
> 2011-09-15 18:18:00,027 - __init__.py[DEBUG]: found data source DataSourceEc2
> 2011-09-15 18:18:00,050 - cloud-init[DEBUG]: found data source: DataSourceEc2
>
>
> Note the 5 second time lapse between 'Using' and 'found'. Using just indicated there the port was open. found actually used data from it.
>
> To manage notifications about this bug go to:
> https:/