RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1746627 - cloud-init: No active metadata service found in aws arm instances
Summary: cloud-init: No active metadata service found in aws arm instances
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: Red Hat Enterprise Linux 8
Classification: Red Hat
Component: cloud-init
Version: 8.1
Hardware: aarch64
OS: Linux
medium
medium
Target Milestone: rc
: 8.1
Assignee: Eduardo Otubo
QA Contact: Frank Liang
URL:
Whiteboard:
Depends On:
Blocks: 1677408
TreeView+ depends on / blocked
 
Reported: 2019-08-29 02:36 UTC by Frank Liang
Modified: 2024-11-21 02:51 UTC (History)
12 users (show)

Fixed In Version: cloud-init-18.5-8.el8.noarch
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-12-20 06:16:14 UTC
Type: Bug
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)
20190829_cloud-init.log (433.35 KB, text/plain)
2019-08-29 02:36 UTC, Frank Liang 		no flags Details
View All

Description Frank Liang 2019-08-29 02:36:25 UTC 
Created attachment 1609179 [details]
20190829_cloud-init.log

In aws ec2 arm instances, cloud-init reports below error in "/var/log/cloud-init.log".

2019-08-29 02:19:09,090 - util.py[DEBUG]: Resolving URL: http://169.254.169.254 took 5.022 seconds
2019-08-29 02:19:09,091 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/openstack' with {'url': 'http://169.254.169.254/openstack', 'allow_redirects': True, 'method': 'GET', 'timeout': 10.0, 'headers': {'User-Agent': 'Cloud-Init/18.5'}} configuration
2019-08-29 02:19:09,097 - url_helper.py[DEBUG]: Read from http://169.254.169.254/openstack (404, 345b) after 1 attempts
2019-08-29 02:19:09,098 - url_helper.py[DEBUG]: Calling 'http://169.254.169.254/openstack' failed [0/-1s]: bad status code [404]
2019-08-29 02:19:09,098 - DataSourceOpenStack.py[DEBUG]: Giving up on OpenStack md from ['http://169.254.169.254/openstack'] after 0 seconds
2019-08-29 02:19:09,098 - util.py[DEBUG]: Crawl of metadata service took 5.030 seconds
2019-08-29 02:19:09,098 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', 'default', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True)
2019-08-29 02:19:09,103 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', '10.116.2.1', 'dev', 'eth0', 'src', '10.116.2.12'] with allowed return codes [0] (shell=False, capture=True)
2019-08-29 02:19:09,109 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'link', 'set', 'dev', 'eth0', 'down'] with allowed return codes [0] (shell=False, capture=True)
2019-08-29 02:19:09,115 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'addr', 'del', '10.116.2.12/24', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True)
2019-08-29 02:19:09,120 - util.py[WARNING]: No active metadata service found
2019-08-29 02:19:09,120 - util.py[DEBUG]: No active metadata service found
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/cloudinit/sources/DataSourceOpenStack.py", line 134, in _get_data
    func=self._crawl_metadata)
  File "/usr/lib/python3.6/site-packages/cloudinit/util.py", line 2520, in log_time
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/cloudinit/sources/DataSourceOpenStack.py", line 177, in _crawl_metadata
    'No active metadata service found')
cloudinit.sources.InvalidMetaDataException: No active metadata service found
2019-08-29 02:19:09,266 - __init__.py[DEBUG]: Datasource DataSourceOpenStackLocal [net,ver=None] not updated for events: New instance first boot
2019-08-29 02:19:09,266 - handlers.py[DEBUG]: finish: init-local/search-OpenStackLocal: SUCCESS: no local data found from DataSourceOpenStackLocal
2019-08-29 02:19:09,267 - handlers.py[DEBUG]: start: init-local/search-Ec2Local: searching for local data from DataSourceEc2Local
2019-08-29 02:19:09,267 - __init__.py[DEBUG]: Seeing if we can get any data from <class 'cloudinit.sources.DataSourceEc2.DataSourceEc2Local'>
2019-08-29 02:19:09,267 - __init__.py[DEBUG]: Update datasource metadata and network config due to events: New instance first boot

Version-Release number of selected component (if applicable):

RHEL Version:
RHEL8.1(4.18.0-135.el8.aarch64)
cloud-init-18.5-7.el8.noarch

How reproducible:
100%

Steps to Reproduce:
1. Launch a new RHEL8.1 a1.medium instance
2. Check the "/var/log/cloud-init.log" after system boot up.

Actual results:
Traceback found as "No active metadata service found"

Expected results:
No such error.

Additional info:
- No such issue in RHEL8.0 arm instance(cloud-init-18.2-6.el8.noarch)
- No such issue in RHEL8.1 x86_64 instance.
Comment 1 Rick Barry 2019-08-29 14:08:28 UTC 
Eduardo, do you think this looks like a cloud-init issue or could it be some AWS ARM infrastructure issue?
Comment 2 Jon Masters 2019-09-10 21:33:40 UTC 
This is the image failing to find an OpenStack metadata source. But I assume it does then find the AWS EC2 metadata and configure correctly. Can you confirm the instance is otherwise working ok?
Comment 3 Frank Liang 2019-10-17 14:59:00 UTC 
(In reply to Jon Masters from comment #2)
> This is the image failing to find an OpenStack metadata source. But I assume
> it does then find the AWS EC2 metadata and configure correctly. Can you
> confirm the instance is otherwise working ok?

Yes, the instance is accessible normally. It happens in each reboot.
Comment 4 Frank Liang 2019-11-21 03:23:45 UTC 
The root cause of this problem is that, detect_openstack() simply return true while running on non-x86 systems.
So in ec2 arm instance, cloudinit detected it as a openstack system by mistake and continue to try to get metadata from "http://169.254.169.254/openstack" which is not available.

In fact, it can get 'Amazon EC2' from chassis-asset-tag and skipped out earlier to fix this issue.

I copied the latest cloudinit sources/DataSourceOpenStack.py for your quick reference. 

def detect_openstack(accept_oracle=False):
    """Return True when a potential OpenStack platform is detected."""
    if not util.is_x86():
        return True  # Non-Intel cpus don't properly report dmi product names
    product_name = util.read_dmi_data('system-product-name')
    if product_name in VALID_DMI_PRODUCT_NAMES:
        return True
    elif util.read_dmi_data('chassis-asset-tag') in VALID_DMI_ASSET_TAGS:
        return True
    elif accept_oracle and oracle._is_platform_viable():
        return True
    elif util.get_proc_env(1).get('product_name') == DMI_PRODUCT_NOVA:
        return True
    return False
Comment 5 Frank Liang 2019-12-20 06:16:14 UTC 
This bug was successfully avoided by 18.5-8.el8 when fixed 1706482.

The current behavior does not scan all data sources in ['NoCloud', 'ConfigDrive', 'OpenNebula', 'DigitalOcean', 'Azure', 'AltCloud', 'OVF', 'MAAS', 'GCE', 'OpenStack', 'AliYun', 'Ec2', 'CloudSigma', 'CloudStack', 'SmartOS', 'Bigstep', 'Scaleway', 'Hetzner', 'IBMCloud', 'Oracle', 'None']. 
According to cloud-init/ds-identify result, it only looks for data source in ['Ec2', 'None']. 

Although the issue I mentioned in Comment 4 is not fxied in DataSourceOpenStack.py, but the customer will not hit such traceback in ec2 arm instances for now. So I am closing this bug as 'CURRENTRELEASE'. If you have different comments, please feel free to re-open it. Thanks
Comment 6 Ravi Singh 2020-04-17 12:29:54 UTC 
Not only in AWS I can see similar traceback in Openstack environment too but instance was booted successfully at the end. But it looks like it took additional time to complete this process & to boot an instance.

Do you want me to open a different BZ?

It's trying to curl http://169.254.169.254/openstack & failed.

~~~
2020-04-17 09:01:12,111 - util.py[DEBUG]: Read 564 bytes from /var/tmp/cloud-init/cloud-init-dhcp-0h85378m/dhcp.leases
2020-04-17 09:01:12,134 - dhcp.py[DEBUG]: Received dhcp lease on eth0 for 192.168.123.96/255.255.255.0
2020-04-17 09:01:12,141 - __init__.py[DEBUG]: Attempting setup of ephemeral network on eth0 with 192.168.123.96/24 brd 192.168.123.255
2020-04-17 09:01:12,144 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'addr', 'add', '192.168.123.96/24', 'broadcast', '192.168.123.255', 'dev', 'eth0'] with a
llowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:12,272 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'link', 'set', 'dev', 'eth0', 'up'] with allowed return codes [0] (shell=False, capture=T
rue)
2020-04-17 09:01:12,386 - util.py[DEBUG]: Running command ['ip', 'route', 'show', '0.0.0.0/0'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:12,491 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'add', '192.168.123.254', 'dev', 'eth0', 'src', '192.168.123.96'] with allowed return codes [
0] (shell=False, capture=True)
2020-04-17 09:01:12,584 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'add', 'default', 'via', '192.168.123.254', 'dev', 'eth0'] with allowed return codes [0] (she
ll=False, capture=True)
2020-04-17 09:01:12,763 - util.py[DEBUG]: Resolving URL: http://169.254.169.254 took 0.076 seconds
2020-04-17 09:01:12,770 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/openstack' with {'url': 'http://169.254.169.254/openstack', 'allow_redirects': True, 'method': 'GET', 'timeout': 10.0, 'headers': {'User-Agent': 'Cloud-Init/18.5'}} configuration
2020-04-17 09:01:22,879 - url_helper.py[DEBUG]: Calling 'http://169.254.169.254/openstack' failed [10/-1s]: request error [HTTPConnectionPool(host='169.254.169.254', port=80): Max retries exceeded with url: /openstack (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x7f950b61d5c0>, 'Connection to 169.254.169.254 timed out. (connect timeout=10.0)'))]
2020-04-17 09:01:22,882 - DataSourceOpenStack.py[DEBUG]: Giving up on OpenStack md from ['http://169.254.169.254/openstack'] after 10 seconds
2020-04-17 09:01:22,885 - util.py[DEBUG]: Crawl of metadata service took 10.201 seconds
2020-04-17 09:01:22,887 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', 'default', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:22,988 - util.py[DEBUG]: Running command ['ip', '-4', 'route', 'del', '192.168.123.254', 'dev', 'eth0', 'src', '192.168.123.96'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:23,128 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'link', 'set', 'dev', 'eth0', 'down'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:23,267 - util.py[DEBUG]: Running command ['ip', '-family', 'inet', 'addr', 'del', '192.168.123.96/24', 'dev', 'eth0'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:01:23,364 - util.py[WARNING]: No active metadata service found
2020-04-17 09:01:23,377 - util.py[DEBUG]: No active metadata service found
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/cloudinit/sources/DataSourceOpenStack.py", line 134, in _get_data
    func=self._crawl_metadata)
  File "/usr/lib/python3.6/site-packages/cloudinit/util.py", line 2520, in log_time
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/cloudinit/sources/DataSourceOpenStack.py", line 177, in _crawl_metadata
    'No active metadata service found')
cloudinit.sources.InvalidMetaDataException: No active metadata service found
~~~~

In messages, I got a response at 09:02 for networking is configured now

~~~

cloud-init[803]: Cloud-init v. 18.5 running 'init' at Fri, 17 Apr 2020 09:02:06 +0000. Up 254.92 seconds.<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: | Device |  Up  |           Address            |      Mask     | Scope  |     Hw-Address    |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |  eth0  | True |        192.168.123.96        | 255.255.255.0 | global | fa:16:3e:a4:9c:e5 |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |  eth0  | True | fe80::f816:3eff:fea4:9ce5/64 |       .       |  link  | fa:16:3e:a4:9c:e5 |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |   lo   | True |          127.0.0.1           |   255.0.0.0   |  host  |         .         |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |   lo   | True |           ::1/128            |       .       |  host  |         .         |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +--------+------+------------------------------+---------------+--------+-------------------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: ++++++++++++++++++++++++++++++++++Route IPv4 info++++++++++++++++++++++++++++++++++
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +-------+-----------------+-----------------+-----------------+-----------+-------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: | Route |   Destination   |     Gateway     |     Genmask     | Interface | Flags |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +-------+-----------------+-----------------+-----------------+-----------+-------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |   0   |     0.0.0.0     | 192.168.123.254 |     0.0.0.0     |    eth0   |   UG  |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |   1   | 169.254.169.254 |  192.168.123.1  | 255.255.255.255 |    eth0   |  UGH  |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: |   2   |  192.168.123.0  |     0.0.0.0     |  255.255.255.0  |    eth0   |   U   |
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +-------+-----------------+-----------------+-----------------+-----------+-------+
Apr 17 05:02:19 rhel cloud-init[803]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++

~~~


Now later on the same url is reachable now


~~~
2020-04-17 09:02:11,460 - util.py[DEBUG]: Running command ['systemd-detect-virt', '--quiet', '--container'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:02:11,614 - util.py[DEBUG]: Running command ['running-in-container'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:02:11,648 - util.py[DEBUG]: Running command ['lxc-is-container'] with allowed return codes [0] (shell=False, capture=True)
2020-04-17 09:02:11,682 - util.py[DEBUG]: Reading from /proc/1/environ (quiet=False)
2020-04-17 09:02:11,687 - util.py[DEBUG]: Read 94 bytes from /proc/1/environ
2020-04-17 09:02:11,689 - util.py[DEBUG]: Reading from /proc/self/status (quiet=False)
2020-04-17 09:02:11,692 - util.py[DEBUG]: Read 1290 bytes from /proc/self/status
2020-04-17 09:02:11,694 - util.py[DEBUG]: querying dmi data /sys/class/dmi/id/product_name
2020-04-17 09:02:11,696 - util.py[DEBUG]: Reading from /sys/class/dmi/id/product_name (quiet=False)
2020-04-17 09:02:11,698 - util.py[DEBUG]: Read 18 bytes from /sys/class/dmi/id/product_name
2020-04-17 09:02:11,699 - util.py[DEBUG]: dmi data /sys/class/dmi/id/product_name returned OpenStack Compute
2020-04-17 09:02:11,760 - util.py[DEBUG]: Resolving URL: http://169.254.169.254 took 0.057 seconds
2020-04-17 09:02:11,766 - url_helper.py[DEBUG]: [0/1] open 'http://169.254.169.254/openstack' with {'url': 'http://169.254.169.254/openstack', 'allow_redirects': True, 'method': 'GET', 'timeout': 10.0, 'headers': {'User-Agent': 'Cloud-Init/18.5'}} configuration
2020-04-17 09:02:13,239 - url_helper.py[DEBUG]: Read from http://169.254.169.254/openstack (200, 94b) after 1 attempts
2020-04-17 09:02:13,243 - DataSourceOpenStack.py[DEBUG]: Using metadata source: 'http://169.254.169.254'
2020-04-17 09:02:13,247 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/openstack' with {'url': 'http://169.254.169.254/openstack', 'allow_redirects': True, 'method': 'GET', 'timeout': 10.0, 'headers': {'User-Agent': 'Cloud-Init/18.5'}} configuration
2020-04-17 09:02:13,367 - url_helper.py[DEBUG]: Read from http://169.254.169.254/openstack (200, 94b) after 1 attempts
2020-04-17 09:02:13,369 - openstack.py[DEBUG]: Selected version '2018-08-27' from ['2012-08-10', '2013-04-04', '2013-10-17', '2015-10-15', '2016-06-30', '2016-10-06', '2017-02-22', '2018-08-27', 'latest']
2020-04-17 09:02:13,376 - url_helper.py[DEBUG]: [0/6] open 'http://169.254.169.254/openstack/2018-08-27/meta_data.json' with {'url': 'http://169.254.169.254/openstack/2018-08-27/meta_data.json', 'allow_redirects': True, 'method': 'GET', 'timeout': 10.0, 'headers': {'User-Agent': 'Cloud-Init/18.5'}} configuration
2020-04-17 09:02:13,459 - url_helper.py[DEBUG]: Read from http://169.254.169.254/openstack/2018-08-27/meta_data.json (200, 1471b) after 1 attempts
~~~
Note You need to log in before you can comment on or make changes to this bug.