[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#1006346: cloud.debian.org: bullseye AMIs don't boot on Amazon EC2 Xen instances with Enhanced Networking



Package: cloud.debian.org
Severity: important

(I suspect this is actually a kernel issue, but I'm starting with
cloud.debian.org as that's where I've observed the issue and I want to rule
out cloud configuration issues.)

Amazon EC2 instance types with Enhanced Networking use the ixgbevf.ko
driver.  The current AMIs successfully probe the ixgbevf driver and spawn
dhclient as expected, but dhclient appears to never receive a lease.  Older
AMIs do work on this class of instance.

Working AMI:

{
    "Images": [
        {
            "Architecture": "x86_64",
            "CreationDate": "2021-12-21T01:39:18.000Z",
            "ImageId": "ami-055b24b622e97e043",
            "ImageLocation": "136693071363/debian-11-amd64-20211220-862",
            "ImageType": "machine",
            "Public": true,
            "OwnerId": "136693071363",
            "PlatformDetails": "Linux/UNIX",
            "UsageOperation": "RunInstances",
            "State": "available",
            "BlockDeviceMappings": [
                {
                    "DeviceName": "/dev/xvda",
                    "Ebs": {
                        "DeleteOnTermination": true,
                        "SnapshotId": "snap-0b1ec9931c8475322",
                        "VolumeSize": 8,
                        "VolumeType": "gp2",
                        "Encrypted": false
                    }
                }
            ],
            "Description": "Debian 11 (20211220-862)",
            "EnaSupport": true,
            "Hypervisor": "xen",
            "Name": "debian-11-amd64-20211220-862",
            "RootDeviceName": "/dev/xvda",
            "RootDeviceType": "ebs",
            "SriovNetSupport": "simple",
            "VirtualizationType": "hvm"
        }
    ]
}

Not working AMI:

{
    "Images": [
        {
            "Architecture": "x86_64",
            "CreationDate": "2022-01-21T15:02:04.000Z",
            "ImageId": "ami-0d0d8694ba492c02b",
            "ImageLocation": "136693071363/debian-11-amd64-20220121-894",
            "ImageType": "machine",
            "Public": true,
            "OwnerId": "136693071363",
            "PlatformDetails": "Linux/UNIX",
            "UsageOperation": "RunInstances",
            "State": "available",
            "BlockDeviceMappings": [
                {
                    "DeviceName": "/dev/xvda",
                    "Ebs": {
                        "DeleteOnTermination": true,
                        "SnapshotId": "snap-0f15c399cd68cf47c",
                        "VolumeSize": 8,
                        "VolumeType": "gp2",
                        "Encrypted": false
                    }
                }
            ],
            "Description": "Debian 11 (20220121-894)",
            "EnaSupport": true,
            "Hypervisor": "xen",
            "Name": "debian-11-amd64-20220121-894",
            "RootDeviceName": "/dev/xvda",
            "RootDeviceType": "ebs",
            "SriovNetSupport": "simple",
            "VirtualizationType": "hvm"
        }
    ]
}

Relevant logs from the instance boot:

Feb 23 22:04:09 debian kernel: [    1.763348] ixgbevf 0000:00:03.0 ens3: renamed from eth0
...
Feb 23 22:04:09 debian kernel: [    5.283750] ixgbevf 0000:00:03.0: NIC Link is Up 10 Gbps
Feb 23 22:04:09 debian kernel: [    5.287656] IPv6: ADDRCONF(NETDEV_CHANGE): ens3: link becomes ready
...
Feb 23 22:04:09 debian systemd-udevd[239]: Using default interface naming scheme 'v247'.
Feb 23 22:04:09 debian systemd-udevd[234]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 23 22:04:09 debian systemd-udevd[239]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
...
Feb 23 22:04:09 debian cloud-ifupdown-helper: Generated configuration for ens3
...
Feb 23 22:04:09 debian systemd[1]: Found device 82599 Ethernet Controller Virtual Function.
...
Feb 23 22:04:09 debian dhclient[345]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:04:09 debian dhclient[345]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:04:09 debian dhclient[345]: All rights reserved.
Feb 23 22:04:09 debian dhclient[345]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:04:09 debian dhclient[345]: 
Feb 23 22:04:09 debian dhclient[345]: Listening on LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian dhclient[345]: Sending on   LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian dhclient[345]: Sending on   Socket/fallback
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 5
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 13
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 8
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 13
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 10
Feb 23 22:04:09 debian dhclient[345]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 12
Feb 23 22:04:09 debian dhclient[345]: No DHCPOFFERS received.
Feb 23 22:04:09 debian dhclient[345]: Unable to obtain a lease on first try.  Exiting.
Feb 23 22:04:09 debian cloud-init[342]: 2022-02-23 22:01:00,593 - util.py[WARNING]: Getting data from <class 'cloudinit.sources.DataSourceEc2.DataSourceEc2Local'> failed
Feb 23 22:04:09 debian systemd[1]: Finished Initial cloud-init job (pre-networking).
Feb 23 22:04:09 debian systemd[1]: Reached target Network (Pre).
Feb 23 22:04:09 debian systemd[1]: Started ifup for ens3.
Feb 23 22:04:09 debian systemd[1]: Starting Raise network interfaces...
Feb 23 22:04:09 debian dhclient[372]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:04:09 debian sh[372]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:04:09 debian sh[372]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:04:09 debian sh[372]: All rights reserved.
Feb 23 22:04:09 debian sh[372]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:04:09 debian dhclient[372]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:04:09 debian dhclient[372]: All rights reserved.
Feb 23 22:04:09 debian dhclient[372]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:04:09 debian dhclient[372]: 
Feb 23 22:04:09 debian ifup[354]: ifup: waiting for lock on /run/network/ifstate.ens3
Feb 23 22:04:09 debian dhclient[372]: Listening on LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian sh[372]: Listening on LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian sh[372]: Sending on   LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian sh[372]: Sending on   Socket/fallback
Feb 23 22:04:09 debian sh[372]: Created duid "\000\001\000\001)\251k\034\002\340\\\007\355\347".
Feb 23 22:04:09 debian dhclient[372]: Sending on   LPF/ens3/02:e0:5c:07:ed:e7
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 5
Feb 23 22:04:09 debian dhclient[372]: Sending on   Socket/fallback
Feb 23 22:04:09 debian dhclient[372]: Created duid "\000\001\000\001)\251k\034\002\340\\\007\355\347".
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 5
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 11
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 11
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 14
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 14
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 15
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 15
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 15
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 15
Feb 23 22:04:09 debian dhclient[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 1
Feb 23 22:04:09 debian sh[372]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 1
Feb 23 22:04:09 debian dhclient[372]: No DHCPOFFERS received.
Feb 23 22:04:09 debian sh[372]: No DHCPOFFERS received.
Feb 23 22:04:09 debian sh[372]: No working leases in persistent database - sleeping.
Feb 23 22:04:09 debian dhclient[372]: No working leases in persistent database - sleeping.
Feb 23 22:04:09 debian dhclient[414]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:04:09 debian sh[414]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:04:09 debian sh[414]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:04:09 debian sh[414]: All rights reserved.
Feb 23 22:04:09 debian sh[414]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:04:09 debian dhclient[414]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:04:09 debian dhclient[414]: All rights reserved.
Feb 23 22:04:09 debian dhclient[414]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:04:09 debian dhclient[414]: 
Feb 23 22:04:09 debian dhclient[414]: Listening on Socket/ens3
Feb 23 22:04:09 debian sh[414]: Listening on Socket/ens3
Feb 23 22:04:09 debian sh[414]: Sending on   Socket/ens3
Feb 23 22:04:09 debian sh[414]: PRC: Soliciting for leases (INIT).
Feb 23 22:04:09 debian dhclient[414]: Sending on   Socket/ens3
Feb 23 22:04:09 debian sh[445]: ens3=ens3
Feb 23 22:04:09 debian systemd[1]: Finished Raise network interfaces.

By comparison, a working instance installs the DHCP configuration quickly:

Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: All rights reserved.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: 
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: Listening on LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: Sending on   LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: Sending on   Socket/fallback
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 3
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: DHCPOFFER of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: DHCPREQUEST for 10.0.0.127 on ens3 to 255.255.255.255 port 67
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: DHCPACK of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[346]: bound to 10.0.0.127 -- renewal in 1515 seconds.
Feb 23 22:48:26 ip-10-0-0-127 systemd[1]: Finished Initial cloud-init job (pre-networking).
Feb 23 22:48:26 ip-10-0-0-127 systemd[1]: Reached target Network (Pre).
Feb 23 22:48:26 ip-10-0-0-127 systemd[1]: Started ifup for ens3.
Feb 23 22:48:26 ip-10-0-0-127 systemd[1]: Starting Raise network interfaces...
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: All rights reserved.
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: All rights reserved.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: 
Feb 23 22:48:26 ip-10-0-0-127 ifup[368]: ifup: waiting for lock on /run/network/ifstate.ens3
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Listening on LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Listening on LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Sending on   LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Sending on   Socket/fallback
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: Created duid "\000\001\000\001)\251v7\002:6\023\015\333".
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Sending on   LPF/ens3/02:3a:36:13:0d:db
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 5
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Sending on   Socket/fallback
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: Created duid "\000\001\000\001)\251v7\002:6\023\015\333".
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: DHCPOFFER of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: DHCPREQUEST for 10.0.0.127 on ens3 to 255.255.255.255 port 67
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: DHCPDISCOVER on ens3 to 255.255.255.255 port 67 interval 5
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: DHCPACK of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: DHCPOFFER of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: DHCPREQUEST for 10.0.0.127 on ens3 to 255.255.255.255 port 67
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: DHCPACK of 10.0.0.127 from 10.0.0.1
Feb 23 22:48:26 ip-10-0-0-127 dhclient[383]: bound to 10.0.0.127 -- renewal in 1668 seconds.
Feb 23 22:48:26 ip-10-0-0-127 sh[383]: bound to 10.0.0.127 -- renewal in 1668 seconds.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: Internet Systems Consortium DHCP Client 4.4.1
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: All rights reserved.
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: Copyright 2004-2018 Internet Systems Consortium.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: All rights reserved.
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: For info, please visit https://www.isc.org/software/dhcp/
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: 
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: Listening on Socket/ens3
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: Listening on Socket/ens3
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: Sending on   Socket/ens3
Feb 23 22:48:26 ip-10-0-0-127 sh[459]: PRC: Soliciting for leases (INIT).
Feb 23 22:48:26 ip-10-0-0-127 dhclient[459]: Sending on   Socket/ens3
Feb 23 22:48:26 ip-10-0-0-127 sh[490]: ens3=ens3
Feb 23 22:48:26 ip-10-0-0-127 systemd[1]: Finished Raise network interfaces.


Reply to: