Azure: Add netplan driver filter when using hv_netvsc driver #539

TheRealFalcon · 2020-08-21T21:27:07Z

Commit message:

Azure: Add netplan driver filter when using hv_netvsc driver

This fixes a long delay during boot of some instances. For Azure instance types using SR-IOV via the Hyper-V netvsc network driver, two network interfaces are created that share the same MAC, but only the virtual device should be configured and used. Updating the netplan configuration to filter on the hv_netvsc driver prevents netplan from trying to figure both devices.

LP: #1830740

This fixes a long delay during boot of some instances. For Azure instance types using SR-IOV via the Hyper-V netvsc network driver, two network interfaces are created that share the same MAC, but only the virtual device should be configured and used. Updating the netplan configuration to filter on the hv_netvsc driver prevents netplan from trying to figure both devices. LP: #1830740

TheRealFalcon · 2020-08-24T19:24:38Z

I tested on an Azure DS2 v2 instance with accelerated networking enabled. This is NOT a problem on first boot (or after a cloud-init clean; reboot), so it was fairly straightforward to check. I did a couple reboots and saw boot times of 1 min, 37 seconds. I uploaded a package with this fix, installed it, cleared out the networking configs in /run/systemd/network and /etc/netplan, ran a cloud-init clean -lr, did a number of reboots and never saw the cloud-init time go over 6 seconds.

raharper · 2020-08-24T21:40:28Z

cloudinit/sources/DataSourceAzure.py

+                        'set-name': nicname
+                    })
+                    # With netvsc, we can get two interfaces that
+                    # share the same MAC, so we need to make sure


Do you have logs for this? There should not be two hv_netvsc interfaces with the same mac; for advanced networking, the kernel bonds an SR_IOV device (which previously was an mxl4_core device, and DatasourceAzure blacklists any interfaces using this driver, so we ignore any physical interfaces that driver).

It's possible there is a different driver doing SRIOV so we're not properly masking out the duplicate mac interface that's really the SRIOV device.

I notice the bug this fixes doesn't have any follow up there w.r.t the logs they posted. It'd be good to update that with:

contents of /etc/netplan/50-cloud-init.yaml

/run/systemd/network/*

grep . -r /sys/class/net/*/address

/var/log/journal

from a failing instance to confirm the premise of this fix.

1. ubuntu@test-b1:~$ cat /etc/netplan/50-cloud-init.yaml # This file is generated from information provided by the datasource. Changes # to it will not persist across an instance reboot. To disable cloud-init's # network configuration capabilities, write a file # /etc/cloud/cloud.cfg.d/99-disable-network-config.cfg with the following: # network: {config: disabled} network: ethernets: eth0: dhcp4: true dhcp4-overrides: route-metric: 100 dhcp6: false match: macaddress: 00:0d:3a:03:44:ad set-name: eth0 version: 2 2. ubuntu@test-b1:~$ cat /run/systemd/network/10-netplan-eth0. 10-netplan-eth0.link 10-netplan-eth0.network ubuntu@test-b1:~$ cat /run/systemd/network/10-netplan-eth0.* [Match] MACAddress=00:0d:3a:03:44:ad [Link] Name=eth0 WakeOnLan=off [Match] MACAddress=00:0d:3a:03:44:ad Name=eth0 [Network] DHCP=ipv4 LinkLocalAddressing=ipv6 [DHCP] RouteMetric=100 UseMTU=true 3. ubuntu@test-b1:~$ grep . -r /sys/class/net/*/address /sys/class/net/eth0/address:00:0d:3a:03:44:ad /sys/class/net/lo/address:00:00:00:00:00:00 /sys/class/net/rename3/address:00:0d:3a:03:44:ad ubuntu@test-b1:~$ ip addr show 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000 link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo valid_lft forever preferred_lft forever inet6 ::1/128 scope host valid_lft forever preferred_lft forever 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP group default qlen 1000 link/ether 00:0d:3a:03:44:ad brd ff:ff:ff:ff:ff:ff inet 10.1.0.4/24 brd 10.1.0.255 scope global eth0 valid_lft forever preferred_lft forever inet6 fe80::20d:3aff:fe03:44ad/64 scope link valid_lft forever preferred_lft forever 3: rename3: <BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master eth0 state UP group default qlen 1000 link/ether 00:0d:3a:03:44:ad brd ff:ff:ff:ff:ff:ff 4. ubuntu@test-b1:~$ cat journal.txt -- Logs begin at Mon 2020-08-24 20:55:29 UTC, end at Mon 2020-08-24 21:52:49 UTC. -- Aug 24 21:45:19.743656 test-b1 kernel: Linux version 5.3.0-1035-azure (buildd@lgw01-amd64-038) (gcc version 7.5.0 (Ubuntu 7.5.0-3ubuntu1~18.04)) #36-Ubuntu SMP Thu Aug 6 09:21:33 UTC 2020 (Ubuntu 5.3.0-1035.36-azure 5.3.18) Aug 24 21:45:19.743678 test-b1 kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-5.3.0-1035-azure root=UUID=43aa5824-44a8-4ef2-a87e-d244df4b80b5 ro console=tty1 console=ttyS0 earlyprintk=ttyS0 Aug 24 21:45:19.743690 test-b1 kernel: KERNEL supported cpus: Aug 24 21:45:19.743698 test-b1 kernel: Intel GenuineIntel Aug 24 21:45:19.743706 test-b1 kernel: AMD AuthenticAMD Aug 24 21:45:19.743715 test-b1 kernel: Hygon HygonGenuine Aug 24 21:45:19.743726 test-b1 kernel: Centaur CentaurHauls Aug 24 21:45:19.743734 test-b1 kernel: zhaoxin Shanghai Aug 24 21:45:19.743743 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers' Aug 24 21:45:19.743754 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers' Aug 24 21:45:19.743763 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers' Aug 24 21:45:19.743771 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x008: 'MPX bounds registers' Aug 24 21:45:19.743780 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x010: 'MPX CSR' Aug 24 21:45:19.743789 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x020: 'AVX-512 opmask' Aug 24 21:45:19.743800 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x040: 'AVX-512 Hi256' Aug 24 21:45:19.743809 test-b1 kernel: x86/fpu: Supporting XSAVE feature 0x080: 'AVX-512 ZMM_Hi256' Aug 24 21:45:19.743818 test-b1 kernel: x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256 Aug 24 21:45:19.743827 test-b1 kernel: x86/fpu: xstate_offset[3]: 832, xstate_sizes[3]: 64 Aug 24 21:45:19.743835 test-b1 kernel: x86/fpu: xstate_offset[4]: 896, xstate_sizes[4]: 64 Aug 24 21:45:19.743844 test-b1 kernel: x86/fpu: xstate_offset[5]: 960, xstate_sizes[5]: 64 Aug 24 21:45:19.743853 test-b1 kernel: x86/fpu: xstate_offset[6]: 1024, xstate_sizes[6]: 512 Aug 24 21:45:19.743861 test-b1 kernel: x86/fpu: xstate_offset[7]: 1536, xstate_sizes[7]: 1024 Aug 24 21:45:19.743870 test-b1 kernel: x86/fpu: Enabled xstate features 0xff, context size is 2560 bytes, using 'compacted' format. Aug 24 21:45:19.743881 test-b1 kernel: BIOS-provided physical RAM map: Aug 24 21:45:19.743890 test-b1 kernel: BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable Aug 24 21:45:19.743898 test-b1 kernel: BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved Aug 24 21:45:19.743907 test-b1 kernel: BIOS-e820: [mem 0x00000000000e0000-0x00000000000fffff] reserved Aug 24 21:45:19.743916 test-b1 kernel: BIOS-e820: [mem 0x0000000000100000-0x000000003ffeffff] usable Aug 24 21:45:19.743925 test-b1 kernel: BIOS-e820: [mem 0x000000003fff0000-0x000000003fffefff] ACPI data Aug 24 21:45:19.743933 test-b1 kernel: BIOS-e820: [mem 0x000000003ffff000-0x000000003fffffff] ACPI NVS Aug 24 21:45:19.743942 test-b1 kernel: BIOS-e820: [mem 0x0000000100000000-0x000000027fffffff] usable Aug 24 21:45:19.743951 test-b1 kernel: printk: bootconsole [earlyser0] enabled Aug 24 21:45:19.743959 test-b1 kernel: NX (Execute Disable) protection: active Aug 24 21:45:19.743968 test-b1 kernel: SMBIOS 2.3 present. Aug 24 21:45:19.743977 test-b1 kernel: DMI: Microsoft Corporation Virtual Machine/Virtual Machine, BIOS 090007 06/02/2017 Aug 24 21:45:19.743985 test-b1 kernel: Hypervisor detected: Microsoft Hyper-V Aug 24 21:45:19.743996 test-b1 kernel: Hyper-V: features 0x2e7f, hints 0x40c2c, misc 0xed7b2 Aug 24 21:45:19.744005 test-b1 kernel: Hyper-V Host Build:14393-10.0-0-0.305 Aug 24 21:45:19.744013 test-b1 kernel: Hyper-V: LAPIC Timer Frequency: 0xc3500 Aug 24 21:45:19.744022 test-b1 kernel: tsc: Marking TSC unstable due to running on Hyper-V Aug 24 21:45:19.744034 test-b1 kernel: Hyper-V: Using hypercall for remote TLB flush Aug 24 21:45:19.744043 test-b1 kernel: tsc: Detected 2095.197 MHz processor Aug 24 21:45:19.744053 test-b1 kernel: e820: update [mem 0x00000000-0x00000fff] usable ==> reserved Aug 24 21:45:19.744064 test-b1 kernel: e820: remove [mem 0x000a0000-0x000fffff] usable Aug 24 21:45:19.744073 test-b1 kernel: last_pfn = 0x280000 max_arch_pfn = 0x400000000 Aug 24 21:45:19.744082 test-b1 kernel: MTRR default type: uncachable Aug 24 21:45:19.744091 test-b1 kernel: MTRR fixed ranges enabled: Aug 24 21:45:19.744100 test-b1 kernel: 00000-9FFFF write-back Aug 24 21:45:19.744109 test-b1 kernel: A0000-DFFFF uncachable Aug 24 21:45:19.744118 test-b1 kernel: E0000-FFFFF write-back Aug 24 21:45:19.744127 test-b1 kernel: MTRR variable ranges enabled: Aug 24 21:45:19.744138 test-b1 kernel: 0 base 00000000000 mask FFFC0000000 write-back Aug 24 21:45:19.744149 test-b1 kernel: 1 base 00100000000 mask FF000000000 write-back Aug 24 21:45:19.744158 test-b1 kernel: 2 disabled Aug 24 21:45:19.744167 test-b1 kernel: 3 disabled Aug 24 21:45:19.744175 test-b1 kernel: 4 disabled Aug 24 21:45:19.744184 test-b1 kernel: 5 disabled Aug 24 21:45:19.744193 test-b1 kernel: 6 disabled Aug 24 21:45:19.744202 test-b1 kernel: 7 disabled Aug 24 21:45:19.744211 test-b1 kernel: x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT Aug 24 21:45:19.744220 test-b1 kernel: e820: update [mem 0x40000000-0xffffffff] usable ==> reserved Aug 24 21:45:19.744229 test-b1 kernel: last_pfn = 0x3fff0 max_arch_pfn = 0x400000000 Aug 24 21:45:19.744240 test-b1 kernel: found SMP MP-table at [mem 0x000ff780-0x000ff78f] Aug 24 21:45:19.744249 test-b1 kernel: check: Scanning 1 areas for low memory corruption Aug 24 21:45:19.744258 test-b1 kernel: Using GB pages for direct mapping Aug 24 21:45:19.744267 test-b1 kernel: RAMDISK: [mem 0x348bd000-0x36455fff] Aug 24 21:45:19.744276 test-b1 kernel: ACPI: Early table checksum verification disabled Aug 24 21:45:19.744285 test-b1 kernel: ACPI: RSDP 0x00000000000F5BF0 000014 (v00 ACPIAM) Aug 24 21:45:19.744295 test-b1 kernel: ACPI: RSDT 0x000000003FFF0000 000040 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744304 test-b1 kernel: ACPI: FACP 0x000000003FFF0200 000081 (v02 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744313 test-b1 kernel: ACPI: DSDT 0x000000003FFF1D24 003CBE (v01 MSFTVM MSFTVM02 00000002 INTL 02002026) Aug 24 21:45:19.744324 test-b1 kernel: ACPI: FACS 0x000000003FFFF000 000040 Aug 24 21:45:19.744333 test-b1 kernel: ACPI: WAET 0x000000003FFF1A80 000028 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744343 test-b1 kernel: ACPI: SLIC 0x000000003FFF1AC0 000176 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744352 test-b1 kernel: ACPI: OEM0 0x000000003FFF1CC0 000064 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744361 test-b1 kernel: ACPI: SRAT 0x000000003FFF0800 000140 (v02 VRTUAL MICROSFT 00000001 MSFT 00000001) Aug 24 21:45:19.744370 test-b1 kernel: ACPI: APIC 0x000000003FFF0300 000452 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744380 test-b1 kernel: ACPI: OEMB 0x000000003FFFF040 000064 (v01 VRTUAL MICROSFT 06001702 MSFT 00000097) Aug 24 21:45:19.744389 test-b1 kernel: ACPI: Local APIC address 0xfee00000 Aug 24 21:45:19.744398 test-b1 kernel: SRAT: PXM 0 -> APIC 0x00 -> Node 0 Aug 24 21:45:19.744408 test-b1 kernel: SRAT: PXM 0 -> APIC 0x01 -> Node 0 Aug 24 21:45:19.744418 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x00000000-0x3fffffff] hotplug Aug 24 21:45:19.744427 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x100000000-0x27fffffff] hotplug Aug 24 21:45:19.744436 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x280200000-0xfdfffffff] hotplug Aug 24 21:45:19.744445 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x1000000000-0xffffffffff] hotplug Aug 24 21:45:19.744454 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x10000200000-0x1ffffffffff] hotplug Aug 24 21:45:19.744464 test-b1 kernel: ACPI: SRAT: Node 0 PXM 0 [mem 0x20000200000-0x3ffffffffff] hotplug Aug 24 21:45:19.744473 test-b1 kernel: NUMA: Node 0 [mem 0x00000000-0x3fffffff] + [mem 0x100000000-0x27fffffff] -> [mem 0x00000000-0x27fffffff] Aug 24 21:45:19.744482 test-b1 kernel: NODE_DATA(0) allocated [mem 0x27ffd5000-0x27fffffff] Aug 24 21:45:19.744493 test-b1 kernel: Zone ranges: Aug 24 21:45:19.744502 test-b1 kernel: DMA [mem 0x0000000000001000-0x0000000000ffffff] Aug 24 21:45:19.744511 test-b1 kernel: DMA32 [mem 0x0000000001000000-0x00000000ffffffff] Aug 24 21:45:19.744520 test-b1 kernel: Normal [mem 0x0000000100000000-0x000000027fffffff] Aug 24 21:45:19.744532 test-b1 kernel: Device empty Aug 24 21:45:19.744541 test-b1 kernel: Movable zone start for each node Aug 24 21:45:19.744550 test-b1 kernel: Early memory node ranges Aug 24 21:45:19.744559 test-b1 kernel: node 0: [mem 0x0000000000001000-0x000000000009efff] Aug 24 21:45:19.744568 test-b1 kernel: node 0: [mem 0x0000000000100000-0x000000003ffeffff] Aug 24 21:45:19.744577 test-b1 kernel: node 0: [mem 0x0000000100000000-0x000000027fffffff] Aug 24 21:45:19.744588 test-b1 kernel: Zeroed struct page in unavailable ranges: 114 pages Aug 24 21:45:19.744598 test-b1 kernel: Initmem setup node 0 [mem 0x0000000000001000-0x000000027fffffff] Aug 24 21:45:19.744607 test-b1 kernel: On node 0 totalpages: 1834894 Aug 24 21:45:19.744616 test-b1 kernel: DMA zone: 64 pages used for memmap Aug 24 21:45:19.744625 test-b1 kernel: DMA zone: 21 pages reserved Aug 24 21:45:19.744634 test-b1 kernel: DMA zone: 3998 pages, LIFO batch:0 Aug 24 21:45:19.744643 test-b1 kernel: DMA32 zone: 4032 pages used for memmap Aug 24 21:45:19.744652 test-b1 kernel: DMA32 zone: 258032 pages, LIFO batch:63 Aug 24 21:45:19.744661 test-b1 kernel: Normal zone: 24576 pages used for memmap Aug 24 21:45:19.744671 test-b1 kernel: Normal zone: 1572864 pages, LIFO batch:63 Aug 24 21:45:19.744680 test-b1 kernel: ACPI: PM-Timer IO Port: 0x408 Aug 24 21:45:19.744689 test-b1 kernel: ACPI: Local APIC address 0xfee00000 Aug 24 21:45:19.744698 test-b1 kernel: ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1]) Aug 24 21:45:19.744707 test-b1 kernel: IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23 Aug 24 21:45:19.744717 test-b1 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) Aug 24 21:45:19.756740 test-b1 kernel: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) Aug 24 21:45:19.756753 test-b1 kernel: ACPI: IRQ0 used by override. Aug 24 21:45:19.756763 test-b1 kernel: ACPI: IRQ9 used by override. Aug 24 21:45:19.756773 test-b1 kernel: Using ACPI (MADT) for SMP configuration information Aug 24 21:45:19.756793 test-b1 kernel: smpboot: Allowing 128 CPUs, 126 hotplug CPUs Aug 24 21:45:19.756806 test-b1 kernel: PM: Registered nosave memory: [mem 0x00000000-0x00000fff] Aug 24 21:45:19.756816 test-b1 kernel: PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff] Aug 24 21:45:19.756826 test-b1 kernel: PM: Registered nosave memory: [mem 0x000a0000-0x000dffff] Aug 24 21:45:19.756836 test-b1 kernel: PM: Registered nosave memory: [mem 0x000e0000-0x000fffff] Aug 24 21:45:19.756846 test-b1 kernel: PM: Registered nosave memory: [mem 0x3fff0000-0x3fffefff] Aug 24 21:45:19.756856 test-b1 kernel: PM: Registered nosave memory: [mem 0x3ffff000-0x3fffffff] Aug 24 21:45:19.756868 test-b1 kernel: PM: Registered nosave memory: [mem 0x40000000-0xffffffff] Aug 24 21:45:19.756878 test-b1 kernel: [mem 0x40000000-0xffffffff] available for PCI devices Aug 24 21:45:19.756888 test-b1 kernel: Booting paravirtualized kernel on bare hardware Aug 24 21:45:19.756899 test-b1 kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns Aug 24 21:45:19.756909 test-b1 kernel: setup_percpu: NR_CPUS:8192 nr_cpumask_bits:128 nr_cpu_ids:128 nr_node_ids:1 Aug 24 21:45:19.756919 test-b1 kernel: percpu: Embedded 53 pages/cpu s180224 r8192 d28672 u262144 Aug 24 21:45:19.756930 test-b1 kernel: pcpu-alloc: s180224 r8192 d28672 u262144 alloc=1*2097152 Aug 24 21:45:19.756939 test-b1 kernel: pcpu-alloc: [0] 000 001 002 003 004 005 006 007 Aug 24 21:45:19.756949 test-b1 kernel: pcpu-alloc: [0] 008 009 010 011 012 013 014 015 Aug 24 21:45:19.756961 test-b1 kernel: pcpu-alloc: [0] 016 017 018 019 020 021 022 023 Aug 24 21:45:19.756972 test-b1 kernel: pcpu-alloc: [0] 024 025 026 027 028 029 030 031 Aug 24 21:45:19.756982 test-b1 kernel: pcpu-alloc: [0] 032 033 034 035 036 037 038 039 Aug 24 21:45:19.756992 test-b1 kernel: pcpu-alloc: [0] 040 041 042 043 044 045 046 047 Aug 24 21:45:19.757001 test-b1 kernel: pcpu-alloc: [0] 048 049 050 051 052 053 054 055 Aug 24 21:45:19.757011 test-b1 kernel: pcpu-alloc: [0] 056 057 058 059 060 061 062 063 Aug 24 21:45:19.757021 test-b1 kernel: pcpu-alloc: [0] 064 065 066 067 068 069 070 071 Aug 24 21:45:19.757031 test-b1 kernel: pcpu-alloc: [0] 072 073 074 075 076 077 078 079 Aug 24 21:45:19.757041 test-b1 kernel: pcpu-alloc: [0] 080 081 082 083 084 085 086 087 Aug 24 21:45:19.757053 test-b1 kernel: pcpu-alloc: [0] 088 089 090 091 092 093 094 095 Aug 24 21:45:19.757063 test-b1 kernel: pcpu-alloc: [0] 096 097 098 099 100 101 102 103 Aug 24 21:45:19.757073 test-b1 kernel: pcpu-alloc: [0] 104 105 106 107 108 109 110 111 Aug 24 21:45:19.757083 test-b1 kernel: pcpu-alloc: [0] 112 113 114 115 116 117 118 119 Aug 24 21:45:19.757093 test-b1 kernel: pcpu-alloc: [0] 120 121 122 123 124 125 126 127 Aug 24 21:45:19.757103 test-b1 kernel: Hyper-V: PV spinlocks enabled Aug 24 21:45:19.757116 test-b1 kernel: PV qspinlock hash table entries: 512 (order: 1, 8192 bytes, linear) Aug 24 21:45:19.757126 test-b1 kernel: Built 1 zonelists, mobility grouping on. Total pages: 1806201 Aug 24 21:45:19.757136 test-b1 kernel: Policy zone: Normal Aug 24 21:45:19.757149 test-b1 kernel: Kernel command line: BOOT_IMAGE=/boot/vmlinuz-5.3.0-1035-azure root=UUID=43aa5824-44a8-4ef2-a87e-d244df4b80b5 ro console=tty1 console=ttyS0 earlyprintk=ttyS0 Aug 24 21:45:19.757159 test-b1 kernel: printk: log_buf_len individual max cpu contribution: 4096 bytes Aug 24 21:45:19.757169 test-b1 kernel: printk: log_buf_len total cpu_extra contributions: 520192 bytes Aug 24 21:45:19.757179 test-b1 kernel: printk: log_buf_len min size: 262144 bytes Aug 24 21:45:19.757189 test-b1 kernel: printk: log_buf_len: 1048576 bytes Aug 24 21:45:19.757199 test-b1 kernel: printk: early log buf free: 251520(95%) Aug 24 21:45:19.757209 test-b1 kernel: Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear) Aug 24 21:45:19.757219 test-b1 kernel: Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear) Aug 24 21:45:19.757230 test-b1 kernel: mem auto-init: stack:off, heap alloc:on, heap free:off Aug 24 21:45:19.757242 test-b1 kernel: Calgary: detecting Calgary via BIOS EBDA area Aug 24 21:45:19.757252 test-b1 kernel: Calgary: Unable to locate Rio Grande table in EBDA - bailing! Aug 24 21:45:19.757263 test-b1 kernel: Memory: 7056868K/7339576K available (14340K kernel code, 2301K rwdata, 4308K rodata, 2440K init, 5368K bss, 282708K reserved, 0K cma-reserved) Aug 24 21:45:19.757273 test-b1 kernel: random: get_random_u64 called from __kmem_cache_create+0x41/0x550 with crng_init=0 Aug 24 21:45:19.757283 test-b1 kernel: SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=128, Nodes=1 Aug 24 21:45:19.757293 test-b1 kernel: Kernel/User page tables isolation: enabled Aug 24 21:45:19.757303 test-b1 kernel: ftrace: allocating 41071 entries in 161 pages Aug 24 21:45:19.757313 test-b1 kernel: rcu: Hierarchical RCU implementation. Aug 24 21:45:19.757324 test-b1 kernel: rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=128. Aug 24 21:45:19.757336 test-b1 kernel: Tasks RCU enabled. Aug 24 21:45:19.757346 test-b1 kernel: rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies. Aug 24 21:45:19.757357 test-b1 kernel: rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=128 Aug 24 21:45:19.757366 test-b1 kernel: NR_IRQS: 524544, nr_irqs: 1448, preallocated irqs: 16 Aug 24 21:45:19.757376 test-b1 kernel: random: crng done (trusting CPU's manufacturer) Aug 24 21:45:19.757388 test-b1 kernel: Console: colour VGA+ 80x25 Aug 24 21:45:19.757398 test-b1 kernel: printk: console [tty1] enabled Aug 24 21:45:19.757408 test-b1 kernel: printk: console [ttyS0] enabled Aug 24 21:45:19.757418 test-b1 kernel: printk: bootconsole [earlyser0] disabled Aug 24 21:45:19.757428 test-b1 kernel: ACPI: Core revision 20190703 Aug 24 21:45:19.757438 test-b1 kernel: APIC: Switch to symmetric I/O mode setup Aug 24 21:45:19.757447 test-b1 kernel: Switched APIC routing to physical flat. Aug 24 21:45:19.757458 test-b1 kernel: Hyper-V: Using IPI hypercalls Aug 24 21:45:19.757467 test-b1 kernel: Hyper-V: Using enlightened APIC (xapic mode) Aug 24 21:45:19.757480 test-b1 kernel: clocksource: hyperv_clocksource_tsc_page: mask: 0xffffffffffffffff max_cycles: 0x24e6a1710, max_idle_ns: 440795202120 ns Aug 24 21:45:19.757490 test-b1 kernel: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1 Aug 24 21:45:19.757500 test-b1 kernel: Calibrating delay loop (skipped), value calculated using timer frequency.. 4190.39 BogoMIPS (lpj=8380788) Aug 24 21:45:19.757510 test-b1 kernel: pid_max: default: 131072 minimum: 1024 Aug 24 21:45:19.757520 test-b1 kernel: LSM: Security Framework initializing Aug 24 21:45:19.757530 test-b1 kernel: Yama: becoming mindful. Aug 24 21:45:19.757540 test-b1 kernel: AppArmor: AppArmor initialized Aug 24 21:45:19.757552 test-b1 kernel: Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) Aug 24 21:45:19.757563 test-b1 kernel: Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear) Aug 24 21:45:19.757572 test-b1 kernel: *** VALIDATE proc *** Aug 24 21:45:19.757584 test-b1 kernel: *** VALIDATE cgroup1 *** Aug 24 21:45:19.757594 test-b1 kernel: *** VALIDATE cgroup2 *** Aug 24 21:45:19.757604 test-b1 kernel: Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8 Aug 24 21:45:19.757614 test-b1 kernel: Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4 Aug 24 21:45:19.757624 test-b1 kernel: Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization Aug 24 21:45:19.757634 test-b1 kernel: Spectre V2 : Mitigation: Full generic retpoline Aug 24 21:45:19.757644 test-b1 kernel: Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch Aug 24 21:45:19.757654 test-b1 kernel: Speculative Store Bypass: Vulnerable Aug 24 21:45:19.757664 test-b1 kernel: TAA: Mitigation: Clear CPU buffers Aug 24 21:45:19.757676 test-b1 kernel: MDS: Mitigation: Clear CPU buffers Aug 24 21:45:19.757686 test-b1 kernel: Freeing SMP alternatives memory: 40K Aug 24 21:45:19.757696 test-b1 kernel: smpboot: CPU0: Intel(R) Xeon(R) Platinum 8171M CPU @ 2.60GHz (family: 0x6, model: 0x55, stepping: 0x4) Aug 24 21:45:19.757707 test-b1 kernel: Performance Events: unsupported p6 CPU model 85 no PMU driver, software events only. Aug 24 21:45:19.757716 test-b1 kernel: rcu: Hierarchical SRCU implementation. Aug 24 21:45:19.757726 test-b1 kernel: NMI watchdog: Perf NMI watchdog permanently disabled Aug 24 21:45:19.757736 test-b1 kernel: smp: Bringing up secondary CPUs ... Aug 24 21:45:19.757746 test-b1 kernel: x86: Booting SMP configuration: Aug 24 21:45:19.757756 test-b1 kernel: .... node #0, CPUs: #1 Aug 24 21:45:19.757768 test-b1 kernel: smp: Brought up 1 node, 2 CPUs Aug 24 21:45:19.757777 test-b1 kernel: smpboot: Max logical packages: 64 Aug 24 21:45:19.757787 test-b1 kernel: smpboot: Total of 2 processors activated (8380.78 BogoMIPS) Aug 24 21:45:19.757797 test-b1 kernel: devtmpfs: initialized Aug 24 21:45:19.757807 test-b1 kernel: x86/mm: Memory block size: 128MB Aug 24 21:45:19.757817 test-b1 kernel: PM: Registering ACPI NVS region [mem 0x3ffff000-0x3fffffff] (4096 bytes) Aug 24 21:45:19.757827 test-b1 kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns Aug 24 21:45:19.757838 test-b1 kernel: futex hash table entries: 32768 (order: 9, 2097152 bytes, linear) Aug 24 21:45:19.757848 test-b1 kernel: pinctrl core: initialized pinctrl subsystem Aug 24 21:45:19.757857 test-b1 kernel: PM: RTC time: 21:45:12, date: 2020-08-24 Aug 24 21:45:19.757869 test-b1 kernel: NET: Registered protocol family 16 Aug 24 21:45:19.757879 test-b1 kernel: audit: initializing netlink subsys (disabled) Aug 24 21:45:19.757889 test-b1 kernel: audit: type=2000 audit(1598305512.212:1): state=initialized audit_enabled=0 res=1 Aug 24 21:45:19.757899 test-b1 kernel: EISA bus registered Aug 24 21:45:19.757909 test-b1 kernel: cpuidle: using governor ladder Aug 24 21:45:19.757919 test-b1 kernel: cpuidle: using governor menu Aug 24 21:45:19.757929 test-b1 kernel: ACPI: bus type PCI registered Aug 24 21:45:19.757939 test-b1 kernel: acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5 Aug 24 21:45:19.757949 test-b1 kernel: PCI: Using configuration type 1 for base access Aug 24 21:45:19.757961 test-b1 kernel: HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages Aug 24 21:45:19.757971 test-b1 kernel: HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages Aug 24 21:45:19.757984 test-b1 kernel: ACPI: Added _OSI(Module Device) Aug 24 21:45:19.757994 test-b1 kernel: ACPI: Added _OSI(Processor Device) Aug 24 21:45:19.758004 test-b1 kernel: ACPI: Added _OSI(3.0 _SCP Extensions) Aug 24 21:45:19.758014 test-b1 kernel: ACPI: Added _OSI(Processor Aggregator Device) Aug 24 21:45:19.758024 test-b1 kernel: ACPI: Added _OSI(Linux-Dell-Video) Aug 24 21:45:19.758034 test-b1 kernel: ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio) Aug 24 21:45:19.758044 test-b1 kernel: ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics) Aug 24 21:45:19.758054 test-b1 kernel: ACPI: 1 ACPI AML tables successfully acquired and loaded Aug 24 21:45:19.758066 test-b1 kernel: ACPI: Interpreter enabled Aug 24 21:45:19.758076 test-b1 kernel: ACPI: (supports S0 S5) Aug 24 21:45:19.758085 test-b1 kernel: ACPI: Using IOAPIC for interrupt routing Aug 24 21:45:19.758096 test-b1 kernel: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug Aug 24 21:45:19.758105 test-b1 kernel: ACPI: Enabled 1 GPEs in block 00 to 0F Aug 24 21:45:19.758116 test-b1 kernel: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff]) Aug 24 21:45:19.758276 test-b1 kernel: acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3] Aug 24 21:45:19.758392 test-b1 kernel: acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge. Aug 24 21:45:19.758408 test-b1 kernel: PCI host bridge to bus 0000:00 Aug 24 21:45:19.758520 test-b1 kernel: pci_bus 0000:00: root bus resource [mem 0xfe0000000-0xfffffffff window] Aug 24 21:45:19.758621 test-b1 kernel: pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window] Aug 24 21:45:19.758721 test-b1 kernel: pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window] Aug 24 21:45:19.758818 test-b1 kernel: pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window] Aug 24 21:45:19.758921 test-b1 kernel: pci_bus 0000:00: root bus resource [mem 0x40000000-0xfffbffff window] Aug 24 21:45:19.759024 test-b1 kernel: pci_bus 0000:00: root bus resource [bus 00-ff] Aug 24 21:45:19.759146 test-b1 kernel: pci 0000:00:00.0: [8086:7192] type 00 class 0x060000 Aug 24 21:45:19.759265 test-b1 kernel: pci 0000:00:07.0: [8086:7110] type 00 class 0x060100 Aug 24 21:45:19.759380 test-b1 kernel: pci 0000:00:07.1: [8086:7111] type 00 class 0x010180 Aug 24 21:45:19.759507 test-b1 kernel: pci 0000:00:07.1: reg 0x20: [io 0xffa0-0xffaf] Aug 24 21:45:19.759611 test-b1 kernel: pci 0000:00:07.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7] Aug 24 21:45:19.759713 test-b1 kernel: pci 0000:00:07.1: legacy IDE quirk: reg 0x14: [io 0x03f6] Aug 24 21:45:19.759818 test-b1 kernel: pci 0000:00:07.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177] Aug 24 21:45:19.759924 test-b1 kernel: pci 0000:00:07.1: legacy IDE quirk: reg 0x1c: [io 0x0376] Aug 24 21:45:19.760028 test-b1 kernel: pci 0000:00:07.3: [8086:7113] type 00 class 0x068000 Aug 24 21:45:19.760040 test-b1 kernel: * Found PM-Timer Bug on the chipset. Due to workarounds for a bug, * this clock source is slow. Consider trying other clock sources Aug 24 21:45:19.760141 test-b1 kernel: pci 0000:00:07.3: acpi_pm_check_blacklist+0x0/0x40 took 11718 usecs Aug 24 21:45:19.760242 test-b1 kernel: pci 0000:00:07.3: quirk: [io 0x0400-0x043f] claimed by PIIX4 ACPI Aug 24 21:45:19.760370 test-b1 kernel: pci 0000:00:08.0: [1414:5353] type 00 class 0x030000 Aug 24 21:45:19.760491 test-b1 kernel: pci 0000:00:08.0: reg 0x10: [mem 0xf8000000-0xfbffffff] Aug 24 21:45:19.760503 test-b1 kernel: ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 7 9 10 *11 12 14 15) Aug 24 21:45:19.760513 test-b1 kernel: ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled. Aug 24 21:45:19.760524 test-b1 kernel: ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled. Aug 24 21:45:19.760534 test-b1 kernel: ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 7 9 10 11 12 14 15) *0, disabled. Aug 24 21:45:19.760544 test-b1 kernel: SCSI subsystem initialized Aug 24 21:45:19.760554 test-b1 kernel: libata version 3.00 loaded. Aug 24 21:45:19.760662 test-b1 kernel: pci 0000:00:08.0: vgaarb: setting as boot VGA device Aug 24 21:45:19.761808 test-b1 kernel: pci 0000:00:08.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none Aug 24 21:45:19.761928 test-b1 kernel: pci 0000:00:08.0: vgaarb: bridge control possible Aug 24 21:45:19.761940 test-b1 kernel: vgaarb: loaded Aug 24 21:45:19.761950 test-b1 kernel: ACPI: bus type USB registered Aug 24 21:45:19.761960 test-b1 kernel: usbcore: registered new interface driver usbfs Aug 24 21:45:19.761970 test-b1 kernel: usbcore: registered new interface driver hub Aug 24 21:45:19.761980 test-b1 kernel: usbcore: registered new device driver usb Aug 24 21:45:19.761990 test-b1 kernel: pps_core: LinuxPPS API ver. 1 registered Aug 24 21:45:19.762001 test-b1 kernel: pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it> Aug 24 21:45:19.762014 test-b1 kernel: PTP clock support registered Aug 24 21:45:19.762024 test-b1 kernel: EDAC MC: Ver: 3.0.0 Aug 24 21:45:19.762034 test-b1 kernel: hv_vmbus: Vmbus version:4.0 Aug 24 21:45:19.762044 test-b1 kernel: PCI: Using ACPI for IRQ routing Aug 24 21:45:19.762054 test-b1 kernel: PCI: pci_cache_line_size set to 64 bytes Aug 24 21:45:19.762065 test-b1 kernel: e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff] Aug 24 21:45:19.762075 test-b1 kernel: e820: reserve RAM buffer [mem 0x3fff0000-0x3fffffff] Aug 24 21:45:19.762085 test-b1 kernel: NetLabel: Initializing Aug 24 21:45:19.762095 test-b1 kernel: NetLabel: domain hash size = 128 Aug 24 21:45:19.762107 test-b1 kernel: NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO Aug 24 21:45:19.762118 test-b1 kernel: NetLabel: unlabeled traffic allowed by default Aug 24 21:45:19.762128 test-b1 kernel: clocksource: Switched to clocksource hyperv_clocksource_tsc_page Aug 24 21:45:19.762138 test-b1 kernel: VFS: Disk quotas dquot_6.6.0 Aug 24 21:45:19.762148 test-b1 kernel: VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) Aug 24 21:45:19.762158 test-b1 kernel: *** VALIDATE hugetlbfs *** Aug 24 21:45:19.762168 test-b1 kernel: AppArmor: AppArmor Filesystem Enabled Aug 24 21:45:19.762178 test-b1 kernel: pnp: PnP ACPI init Aug 24 21:45:19.762290 test-b1 kernel: pnp 00:00: Plug and Play ACPI device, IDs PNP0b00 (active) Aug 24 21:45:19.765260 test-b1 kernel: pnp 00:01: Plug and Play ACPI device, IDs PNP0303 PNP030b (active) Aug 24 21:45:19.765373 test-b1 kernel: pnp 00:02: Plug and Play ACPI device, IDs PNP0f03 PNP0f13 (active) Aug 24 21:45:19.765478 test-b1 kernel: pnp 00:03: [dma 0 disabled] Aug 24 21:45:19.765585 test-b1 kernel: pnp 00:03: Plug and Play ACPI device, IDs PNP0501 (active) Aug 24 21:45:19.765695 test-b1 kernel: pnp 00:04: [dma 0 disabled] Aug 24 21:45:19.765803 test-b1 kernel: pnp 00:04: Plug and Play ACPI device, IDs PNP0501 (active) Aug 24 21:45:19.765917 test-b1 kernel: pnp 00:05: [dma 2] Aug 24 21:45:19.766021 test-b1 kernel: pnp 00:05: Plug and Play ACPI device, IDs PNP0700 (active) Aug 24 21:45:19.766125 test-b1 kernel: system 00:06: [io 0x01e0-0x01ef] has been reserved Aug 24 21:45:19.766244 test-b1 kernel: system 00:06: [io 0x0160-0x016f] has been reserved Aug 24 21:45:19.766339 test-b1 kernel: system 00:06: [io 0x0278-0x027f] has been reserved Aug 24 21:45:19.766433 test-b1 kernel: system 00:06: [io 0x0378-0x037f] has been reserved Aug 24 21:45:19.769035 test-b1 kernel: system 00:06: [io 0x0678-0x067f] has been reserved Aug 24 21:45:19.769149 test-b1 kernel: system 00:06: [io 0x0778-0x077f] has been reserved Aug 24 21:45:19.769255 test-b1 kernel: system 00:06: [io 0x04d0-0x04d1] has been reserved Aug 24 21:45:19.769360 test-b1 kernel: system 00:06: Plug and Play ACPI device, IDs PNP0c02 (active) Aug 24 21:45:19.769464 test-b1 kernel: system 00:07: [io 0x0400-0x043f] has been reserved Aug 24 21:45:19.769566 test-b1 kernel: system 00:07: [io 0x0370-0x0371] has been reserved Aug 24 21:45:19.769673 test-b1 kernel: system 00:07: [io 0x0440-0x044f] has been reserved Aug 24 21:45:19.769774 test-b1 kernel: system 00:07: [mem 0xfec00000-0xfec00fff] could not be reserved Aug 24 21:45:19.769881 test-b1 kernel: system 00:07: [mem 0xfee00000-0xfee00fff] has been reserved Aug 24 21:45:19.769986 test-b1 kernel: system 00:07: Plug and Play ACPI device, IDs PNP0c02 (active) Aug 24 21:45:19.770103 test-b1 kernel: system 00:08: [mem 0x00000000-0x0009ffff] could not be reserved Aug 24 21:45:19.770208 test-b1 kernel: system 00:08: [mem 0x000c0000-0x000dffff] could not be reserved Aug 24 21:45:19.770429 test-b1 kernel: system 00:08: [mem 0x000e0000-0x000fffff] could not be reserved Aug 24 21:45:19.776105 test-b1 kernel: system 00:08: [mem 0x00100000-0x3fffffff] could not be reserved Aug 24 21:45:19.776229 test-b1 kernel: system 00:08: [mem 0xfffc0000-0xffffffff] has been reserved Aug 24 21:45:19.776346 test-b1 kernel: system 00:08: Plug and Play ACPI device, IDs PNP0c01 (active) Aug 24 21:45:19.776362 test-b1 kernel: pnp: PnP ACPI: found 9 devices Aug 24 21:45:19.776373 test-b1 kernel: thermal_sys: Registered thermal governor 'fair_share' Aug 24 21:45:19.776384 test-b1 kernel: thermal_sys: Registered thermal governor 'bang_bang' Aug 24 21:45:19.776405 test-b1 kernel: thermal_sys: Registered thermal governor 'step_wise' Aug 24 21:45:19.776414 test-b1 kernel: thermal_sys: Registered thermal governor 'user_space' Aug 24 21:45:19.776424 test-b1 kernel: thermal_sys: Registered thermal governor 'power_allocator' Aug 24 21:45:19.776433 test-b1 kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns Aug 24 21:45:19.776569 test-b1 kernel: pci_bus 0000:00: resource 4 [mem 0xfe0000000-0xfffffffff window] Aug 24 21:45:19.781253 test-b1 kernel: pci_bus 0000:00: resource 5 [io 0x0000-0x0cf7 window] Aug 24 21:45:19.781386 test-b1 kernel: pci_bus 0000:00: resource 6 [io 0x0d00-0xffff window] Aug 24 21:45:19.784389 test-b1 kernel: pci_bus 0000:00: resource 7 [mem 0x000a0000-0x000bffff window] Aug 24 21:45:19.784494 test-b1 kernel: pci_bus 0000:00: resource 8 [mem 0x40000000-0xfffbffff window] Aug 24 21:45:19.784506 test-b1 kernel: NET: Registered protocol family 2 Aug 24 21:45:19.784517 test-b1 kernel: tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear) Aug 24 21:45:19.784528 test-b1 kernel: TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear) Aug 24 21:45:19.784538 test-b1 kernel: TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear) Aug 24 21:45:19.784549 test-b1 kernel: TCP: Hash tables configured (established 65536 bind 65536) Aug 24 21:45:19.784563 test-b1 kernel: UDP hash table entries: 4096 (order: 5, 131072 bytes, linear) Aug 24 21:45:19.784573 test-b1 kernel: UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear) Aug 24 21:45:19.784584 test-b1 kernel: NET: Registered protocol family 1 Aug 24 21:45:19.784609 test-b1 kernel: NET: Registered protocol family 44 Aug 24 21:45:19.784776 test-b1 kernel: pci 0000:00:00.0: Limiting direct PCI/PCI transfers Aug 24 21:45:19.784909 test-b1 kernel: pci 0000:00:08.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff] Aug 24 21:45:19.784922 test-b1 kernel: PCI: CLS 0 bytes, default 64 Aug 24 21:45:19.784933 test-b1 kernel: Trying to unpack rootfs image as initramfs... Aug 24 21:45:19.784943 test-b1 kernel: Freeing initrd memory: 28260K Aug 24 21:45:19.784954 test-b1 kernel: PCI-DMA: Using software bounce buffering for IO (SWIOTLB) Aug 24 21:45:19.784965 test-b1 kernel: software IO TLB: mapped [mem 0x3bff0000-0x3fff0000] (64MB) Aug 24 21:45:19.784975 test-b1 kernel: check: Scanning for low memory corruption every 60 seconds Aug 24 21:45:19.784989 test-b1 kernel: Initialise system trusted keyrings Aug 24 21:45:19.784999 test-b1 kernel: Key type blacklist registered Aug 24 21:45:19.785009 test-b1 kernel: workingset: timestamp_bits=36 max_order=21 bucket_order=0 Aug 24 21:45:19.785020 test-b1 kernel: zbud: loaded Aug 24 21:45:19.785030 test-b1 kernel: squashfs: version 4.0 (2009/01/31) Phillip Lougher Aug 24 21:45:19.788243 test-b1 kernel: fuse: init (API version 7.31) Aug 24 21:45:19.788254 test-b1 kernel: Platform Keyring initialized Aug 24 21:45:19.788265 test-b1 kernel: Key type asymmetric registered Aug 24 21:45:19.788275 test-b1 kernel: Asymmetric key parser 'x509' registered Aug 24 21:45:19.788289 test-b1 kernel: Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244) Aug 24 21:45:19.788300 test-b1 kernel: io scheduler mq-deadline registered Aug 24 21:45:19.788310 test-b1 kernel: shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 Aug 24 21:45:19.788320 test-b1 kernel: intel_idle: Please enable MWAIT in BIOS SETUP Aug 24 21:45:19.788331 test-b1 kernel: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0 Aug 24 21:45:19.788342 test-b1 kernel: ACPI: Power Button [PWRF] Aug 24 21:45:19.788352 test-b1 kernel: Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled Aug 24 21:45:19.788363 test-b1 kernel: 00:03: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A Aug 24 21:45:19.788373 test-b1 kernel: 00:04: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A Aug 24 21:45:19.788386 test-b1 kernel: Linux agpgart interface v0.103 Aug 24 21:45:19.788396 test-b1 kernel: loop: module loaded Aug 24 21:45:19.788406 test-b1 kernel: hv_vmbus: registering driver hv_storvsc Aug 24 21:45:19.789743 test-b1 kernel: ata_piix 0000:00:07.1: version 2.13 Aug 24 21:45:19.792242 test-b1 kernel: ata_piix 0000:00:07.1: Hyper-V Virtual Machine detected, ATA device ignore set Aug 24 21:45:19.796634 test-b1 kernel: scsi host1: storvsc_host_t Aug 24 21:45:19.796803 test-b1 kernel: scsi host4: ata_piix Aug 24 21:45:19.796959 test-b1 kernel: scsi host3: storvsc_host_t Aug 24 21:45:19.797094 test-b1 kernel: scsi host5: ata_piix Aug 24 21:45:19.797107 test-b1 kernel: scsi: waiting for bus probes to complete ... Aug 24 21:45:19.797118 test-b1 kernel: ata1: PATA max UDMA/33 cmd 0x1f0 ctl 0x3f6 bmdma 0xffa0 irq 14 Aug 24 21:45:19.797129 test-b1 kernel: ata2: PATA max UDMA/33 cmd 0x170 ctl 0x376 bmdma 0xffa8 irq 15 Aug 24 21:45:19.800751 test-b1 kernel: scsi host0: storvsc_host_t Aug 24 21:45:19.800770 test-b1 kernel: libphy: Fixed MDIO Bus: probed Aug 24 21:45:19.800914 test-b1 kernel: scsi host2: storvsc_host_t Aug 24 21:45:19.800928 test-b1 kernel: tun: Universal TUN/TAP device driver, 1.6 Aug 24 21:45:19.803988 test-b1 kernel: scsi 1:0:1:0: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5 Aug 24 21:45:19.804006 test-b1 kernel: PPP generic driver version 2.4.2 Aug 24 21:45:19.804018 test-b1 kernel: scsi: waiting for bus probes to complete ... Aug 24 21:45:19.804029 test-b1 kernel: i8042: PNP: PS/2 Controller [PNP0303:PS2K,PNP0f03:PS2M] at 0x60,0x64 irq 1,12 Aug 24 21:45:19.804191 test-b1 kernel: sd 1:0:1:0: Attached scsi generic sg0 type 0 Aug 24 21:45:19.804204 test-b1 kernel: serio: i8042 KBD port at 0x60,0x64 irq 1 Aug 24 21:45:19.804371 test-b1 kernel: sd 1:0:1:0: [sda] 29360128 512-byte logical blocks: (15.0 GB/14.0 GiB) Aug 24 21:45:19.804384 test-b1 kernel: serio: i8042 AUX port at 0x60,0x64 irq 12 Aug 24 21:45:19.804555 test-b1 kernel: sd 1:0:1:0: [sda] 4096-byte physical blocks Aug 24 21:45:19.804748 test-b1 kernel: sd 1:0:1:0: [sda] Write Protect is off Aug 24 21:45:19.804761 test-b1 kernel: mousedev: PS/2 mouse device common for all mice Aug 24 21:45:19.804926 test-b1 kernel: sd 1:0:1:0: [sda] Mode Sense: 0f 00 10 00 Aug 24 21:45:19.805050 test-b1 kernel: rtc_cmos 00:00: RTC can wake from S4 Aug 24 21:45:19.809829 test-b1 kernel: sd 1:0:1:0: [sda] Write cache: disabled, read cache: enabled, supports DPO and FUA Aug 24 21:45:19.809843 test-b1 kernel: sda: sda1 Aug 24 21:45:19.809998 test-b1 kernel: sd 1:0:1:0: [sda] Attached SCSI disk Aug 24 21:45:19.810109 test-b1 kernel: rtc_cmos 00:00: registered as rtc0 Aug 24 21:45:19.810213 test-b1 kernel: rtc_cmos 00:00: alarms up to one month, 114 bytes nvram Aug 24 21:45:19.810225 test-b1 kernel: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1 Aug 24 21:45:19.810236 test-b1 kernel: device-mapper: uevent: version 1.0.3 Aug 24 21:45:19.810250 test-b1 kernel: device-mapper: ioctl: 4.40.0-ioctl (2019-01-18) initialised: dm-devel@redhat.com Aug 24 21:45:19.810361 test-b1 kernel: platform eisa.0: Probing EISA bus 0 Aug 24 21:45:19.844482 test-b1 kernel: platform eisa.0: EISA: Cannot allocate resource for mainboard Aug 24 21:45:19.844674 test-b1 kernel: scsi 0:0:0:0: Direct-Access Msft Virtual Disk 1.0 PQ: 0 ANSI: 5 Aug 24 21:45:19.844923 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 1 Aug 24 21:45:19.845045 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 2 Aug 24 21:45:19.850023 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 3 Aug 24 21:45:19.850149 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 4 Aug 24 21:45:19.850257 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 5 Aug 24 21:45:19.850359 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 6 Aug 24 21:45:19.850462 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 7 Aug 24 21:45:19.850574 test-b1 kernel: platform eisa.0: Cannot allocate resource for EISA slot 8 Aug 24 21:45:19.850692 test-b1 kernel: platform eisa.0: EISA: Detected 0 cards Aug 24 21:45:19.850705 test-b1 kernel: intel_pstate: CPU model not supported Aug 24 21:45:19.850716 test-b1 kernel: NET: Registered protocol family 10 Aug 24 21:45:19.850727 test-b1 kernel: Segment Routing with IPv6 Aug 24 21:45:19.850737 test-b1 kernel: NET: Registered protocol family 17 Aug 24 21:45:19.850748 test-b1 kernel: Key type dns_resolver registered Aug 24 21:45:19.850758 test-b1 kernel: ata2.01: NODEV after polling detection Aug 24 21:45:19.850769 test-b1 kernel: ata1.01: host indicates ignore ATA devices, ignored Aug 24 21:45:19.850956 test-b1 kernel: sd 0:0:0:0: Attached scsi generic sg1 type 0 Aug 24 21:45:19.850969 test-b1 kernel: RAS: Correctable Errors collector initialized. Aug 24 21:45:19.850980 test-b1 kernel: ata2.00: ATAPI: Virtual CD, , max MWDMA2 Aug 24 21:45:19.850991 test-b1 kernel: ata1.00: host indicates ignore ATA devices, ignored Aug 24 21:45:19.851001 test-b1 kernel: registered taskstats version 1 Aug 24 21:45:19.862752 test-b1 kernel: sd 0:0:0:0: [sdb] 62916608 512-byte logical blocks: (32.2 GB/30.0 GiB) Aug 24 21:45:19.862780 test-b1 kernel: Loading compiled-in X.509 certificates Aug 24 21:45:19.862966 test-b1 kernel: sd 0:0:0:0: [sdb] 4096-byte physical blocks Aug 24 21:45:19.862980 test-b1 kernel: Loaded X.509 cert 'Build time autogenerated kernel key: 269509044521d05e78ff9a0d6b1434378fbf5ba2' Aug 24 21:45:19.863164 test-b1 kernel: sd 0:0:0:0: [sdb] Write Protect is off Aug 24 21:45:19.863319 test-b1 kernel: scsi 5:0:0:0: CD-ROM Msft Virtual CD/ROM 1.0 PQ: 0 ANSI: 5 Aug 24 21:45:19.866908 test-b1 kernel: sd 0:0:0:0: [sdb] Mode Sense: 0f 00 10 00 Aug 24 21:45:19.866925 test-b1 kernel: zswap: loaded using pool lzo/zbud Aug 24 21:45:19.867084 test-b1 kernel: sd 0:0:0:0: [sdb] Write cache: enabled, read cache: enabled, supports DPO and FUA Aug 24 21:45:19.867097 test-b1 kernel: sdb: sdb1 sdb14 sdb15 Aug 24 21:45:19.867108 test-b1 kernel: Key type big_key registered Aug 24 21:45:19.867261 test-b1 kernel: sd 0:0:0:0: [sdb] Attached SCSI disk Aug 24 21:45:19.867277 test-b1 kernel: Key type encrypted registered Aug 24 21:45:19.867288 test-b1 kernel: AppArmor: AppArmor sha1 policy hashing enabled Aug 24 21:45:19.867299 test-b1 kernel: ima: No TPM chip found, activating TPM-bypass! Aug 24 21:45:19.867309 test-b1 kernel: ima: Allocated hash algorithm: sha1 Aug 24 21:45:19.867445 test-b1 kernel: sr 5:0:0:0: [sr0] scsi3-mmc drive: 0x/0x tray Aug 24 21:45:19.867458 test-b1 kernel: No architecture policies found Aug 24 21:45:19.867468 test-b1 kernel: evm: Initialising EVM extended attributes: Aug 24 21:45:19.867479 test-b1 kernel: cdrom: Uniform CD-ROM driver Revision: 3.20 Aug 24 21:45:19.867489 test-b1 kernel: evm: security.selinux Aug 24 21:45:19.867631 test-b1 kernel: sr 5:0:0:0: Attached scsi CD-ROM sr0 Aug 24 21:45:19.867643 test-b1 kernel: evm: security.SMACK64 Aug 24 21:45:19.867779 test-b1 kernel: sr 5:0:0:0: Attached scsi generic sg2 type 5 Aug 24 21:45:19.867791 test-b1 kernel: evm: security.SMACK64EXEC Aug 24 21:45:19.867801 test-b1 kernel: evm: security.SMACK64TRANSMUTE Aug 24 21:45:19.867829 test-b1 kernel: evm: security.SMACK64MMAP Aug 24 21:45:19.867840 test-b1 kernel: evm: security.apparmor Aug 24 21:45:19.867851 test-b1 kernel: evm: security.ima Aug 24 21:45:19.867861 test-b1 kernel: evm: security.capability Aug 24 21:45:19.867872 test-b1 kernel: evm: HMAC attrs: 0x1 Aug 24 21:45:19.867896 test-b1 kernel: PM: Magic number: 0:282:804 Aug 24 21:45:19.868029 test-b1 kernel: rtc_cmos 00:00: setting system clock to 2020-08-24T21:45:15 UTC (1598305515) Aug 24 21:45:19.868045 test-b1 kernel: Unstable clock detected, switching default tracing clock to "global" If you want to keep using the local clock, then add: "trace_clock=local" on the kernel command line Aug 24 21:45:19.868056 test-b1 kernel: Freeing unused decrypted memory: 2040K Aug 24 21:45:19.868065 test-b1 kernel: Freeing unused kernel image memory: 2440K Aug 24 21:45:19.868077 test-b1 kernel: Write protecting the kernel read-only data: 22528k Aug 24 21:45:19.868088 test-b1 kernel: Freeing unused kernel image memory: 2000K Aug 24 21:45:19.868097 test-b1 kernel: Freeing unused kernel image memory: 1836K Aug 24 21:45:19.869042 test-b1 kernel: x86/mm: Checked W+X mappings: passed, no W+X pages found. Aug 24 21:45:19.869055 test-b1 kernel: x86/mm: Checking user space page tables Aug 24 21:45:19.869066 test-b1 kernel: x86/mm: Checked W+X mappings: passed, no W+X pages found. Aug 24 21:45:19.869082 test-b1 kernel: Run /init as init process Aug 24 21:45:19.869093 test-b1 kernel: hv_vmbus: registering driver hyperv_fb Aug 24 21:45:19.869103 test-b1 kernel: hyperv_fb: Screen resolution: 1152x864, Color depth: 32 Aug 24 21:45:19.869114 test-b1 kernel: hv_utils: Registering HyperV Utility Driver Aug 24 21:45:19.869128 test-b1 kernel: hv_vmbus: registering driver hv_utils Aug 24 21:45:19.869138 test-b1 kernel: Console: switching to colour frame buffer device 144x54 Aug 24 21:45:19.869149 test-b1 kernel: hidraw: raw HID events driver (C) Jiri Kosina Aug 24 21:45:19.869159 test-b1 kernel: hv_vmbus: registering driver hid_hyperv Aug 24 21:45:19.869170 test-b1 kernel: hv_utils: Heartbeat IC version 3.0 Aug 24 21:45:19.869180 test-b1 kernel: hv_utils: Shutdown IC version 3.0 Aug 24 21:45:19.869191 test-b1 kernel: hv_utils: VSS IC version 5.0 Aug 24 21:45:19.869201 test-b1 kernel: hv_utils: TimeSync IC version 4.0 Aug 24 21:45:19.869212 test-b1 kernel: input: Microsoft Vmbus HID-compliant Mouse as /devices/0006:045E:0621.0001/input/input3 Aug 24 21:45:19.869365 test-b1 kernel: hid 0006:045E:0621.0001: input: <UNKNOWN> HID v0.01 Mouse [Microsoft Vmbus HID-compliant Mouse] on Aug 24 21:45:19.869380 test-b1 kernel: hv_vmbus: registering driver hv_netvsc Aug 24 21:45:19.869391 test-b1 kernel: hv_vmbus: registering driver hyperv_keyboard Aug 24 21:45:19.869402 test-b1 kernel: input: AT Translated Set 2 keyboard as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A03:00/device:07/VMBUS:01/d34b2567-b9b6-42b9-8778-0a4ec0b955bf/serio2/input/input4 Aug 24 21:45:19.869412 test-b1 kernel: cryptd: max_cpu_qlen set to 1000 Aug 24 21:45:19.869423 test-b1 kernel: AVX2 version of gcm_enc/dec engaged. Aug 24 21:45:19.869433 test-b1 kernel: AES CTR mode by8 optimization enabled Aug 24 21:45:19.869583 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: VF slot 1 added Aug 24 21:45:19.869600 test-b1 kernel: raid6: avx512x4 gen() 30174 MB/s Aug 24 21:45:19.869610 test-b1 kernel: raid6: avx512x4 xor() 15570 MB/s Aug 24 21:45:19.869621 test-b1 kernel: raid6: avx512x2 gen() 27708 MB/s Aug 24 21:45:19.869631 test-b1 kernel: raid6: avx512x2 xor() 17084 MB/s Aug 24 21:45:19.869642 test-b1 kernel: raid6: avx512x1 gen() 24818 MB/s Aug 24 21:45:19.869652 test-b1 kernel: raid6: avx512x1 xor() 14300 MB/s Aug 24 21:45:19.869663 test-b1 kernel: raid6: avx2x4 gen() 24218 MB/s Aug 24 21:45:19.869673 test-b1 kernel: raid6: avx2x4 xor() 15872 MB/s Aug 24 21:45:19.869684 test-b1 kernel: raid6: avx2x2 gen() 21639 MB/s Aug 24 21:45:19.869694 test-b1 kernel: raid6: avx2x2 xor() 14478 MB/s Aug 24 21:45:19.869707 test-b1 kernel: raid6: avx2x1 gen() 16722 MB/s Aug 24 21:45:19.869717 test-b1 kernel: raid6: avx2x1 xor() 13231 MB/s Aug 24 21:45:19.869730 test-b1 kernel: raid6: sse2x4 gen() 9243 MB/s Aug 24 21:45:19.869740 test-b1 kernel: raid6: sse2x4 xor() 5579 MB/s Aug 24 21:45:19.869751 test-b1 kernel: raid6: sse2x2 gen() 8637 MB/s Aug 24 21:45:19.869761 test-b1 kernel: raid6: sse2x2 xor() 5499 MB/s Aug 24 21:45:19.869772 test-b1 kernel: raid6: sse2x1 gen() 7860 MB/s Aug 24 21:45:19.869782 test-b1 kernel: raid6: sse2x1 xor() 4124 MB/s Aug 24 21:45:19.869793 test-b1 kernel: raid6: using algorithm avx512x4 gen() 30174 MB/s Aug 24 21:45:19.869803 test-b1 kernel: raid6: .... xor() 15570 MB/s, rmw enabled Aug 24 21:45:19.869816 test-b1 kernel: raid6: using avx512x2 recovery algorithm Aug 24 21:45:19.869827 test-b1 kernel: xor: automatically using best checksumming function avx Aug 24 21:45:19.869837 test-b1 kernel: async_tx: api initialized (async) Aug 24 21:45:19.869848 test-b1 kernel: Btrfs loaded, crc32c=crc32c-intel Aug 24 21:45:19.869858 test-b1 kernel: EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: (null) Aug 24 21:45:19.869872 test-b1 systemd[1]: systemd 237 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) Aug 24 21:45:19.869885 test-b1 systemd[1]: Detected virtualization microsoft. Aug 24 21:45:19.869899 test-b1 systemd[1]: Detected architecture x86-64. Aug 24 21:45:19.869910 test-b1 systemd[1]: Set hostname to <test-b1>. Aug 24 21:45:19.869921 test-b1 systemd[1]: Reached target User and Group Name Lookups. Aug 24 21:45:19.869932 test-b1 systemd[1]: Started Forward Password Requests to Wall Directory Watch. Aug 24 21:45:19.869943 test-b1 systemd[1]: Reached target Swap. Aug 24 21:45:19.869954 test-b1 systemd[1]: Created slice User and Session Slice. Aug 24 21:45:19.869965 test-b1 systemd[1]: Created slice System Slice. Aug 24 21:45:19.869976 test-b1 systemd[1]: Listening on Journal Audit Socket. Aug 24 21:45:19.869986 test-b1 kernel: EXT4-fs (sdb1): re-mounted. Opts: discard Aug 24 21:45:19.869999 test-b1 kernel: Loading iSCSI transport class v2.0-870. Aug 24 21:45:19.870009 test-b1 kernel: iscsi: registered transport (tcp) Aug 24 21:45:19.870022 test-b1 kernel: iscsi: registered transport (iser) Aug 24 21:45:19.870035 test-b1 systemd-journald[442]: Journal started Aug 24 21:45:19.870089 test-b1 systemd-journald[442]: Runtime journal (/run/log/journal/c39e69b123ce4831b99052faece75233) is 8.0M, max 69.2M, 61.2M free. Aug 24 21:45:19.873710 test-b1 systemd-modules-load[424]: Inserted module 'iscsi_tcp' Aug 24 21:45:19.873948 test-b1 systemd-modules-load[424]: Inserted module 'ib_iser' Aug 24 21:45:19.877936 test-b1 systemd[1]: Starting Flush Journal to Persistent Storage... Aug 24 21:45:19.887270 test-b1 systemd-journald[442]: Time spent on flushing to /var is 10.100ms for 547 entries. Aug 24 21:45:19.887270 test-b1 systemd-journald[442]: System journal (/var/log/journal/c39e69b123ce4831b99052faece75233) is 16.0M, max 2.8G, 2.8G free. Aug 24 21:45:19.894868 test-b1 systemd[1]: Started Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling. Aug 24 21:45:19.900626 test-b1 systemd[1]: Reached target Local File Systems (Pre). Aug 24 21:45:19.912012 test-b1 systemd[1]: Started udev Kernel Device Manager. Aug 24 21:45:19.922003 test-b1 systemd[1]: Started Flush Journal to Persistent Storage. Aug 24 21:45:19.945081 test-b1 systemd[1]: Started udev Coldplug all Devices. Aug 24 21:45:19.949145 test-b1 systemd[1]: Started Dispatch Password Requests to Console Directory Watch. Aug 24 21:45:19.954048 test-b1 systemd[1]: Reached target Local Encrypted Volumes. Aug 24 21:45:20.088896 test-b1 kernel: hv_vmbus: registering driver hv_balloon Aug 24 21:45:20.094875 test-b1 kernel: hv_vmbus: registering driver hv_pci Aug 24 21:45:20.094942 test-b1 kernel: hv_pci 11a0f8fe-7993-499d-b2a2-ce823de97264: PCI VMBus probing: Using version 0x10002 Aug 24 21:45:20.095147 test-b1 kernel: hv_balloon: Using Dynamic Memory protocol version 2.0 Aug 24 21:45:20.105027 test-b1 kernel: hv_pci 11a0f8fe-7993-499d-b2a2-ce823de97264: PCI host bridge to bus 7993:00 Aug 24 21:45:20.105224 test-b1 kernel: pci_bus 7993:00: root bus resource [mem 0xfe0000000-0xfe00fffff window] Aug 24 21:45:20.111294 test-b1 systemd-udevd[464]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 24 21:45:20.111317 test-b1 systemd-udevd[464]: Could not set WakeOnLan of eth0 to off: Operation not supported Aug 24 21:45:20.117028 test-b1 kernel: pci 7993:00:02.0: [15b3:1016] type 00 class 0x020000 Aug 24 21:45:20.124853 test-b1 kernel: pci 7993:00:02.0: reg 0x10: [mem 0xfe0000000-0xfe00fffff 64bit pref] Aug 24 21:45:20.145097 test-b1 kernel: pci 7993:00:02.0: enabling Extended Tags Aug 24 21:45:20.157457 test-b1 kernel: pci 7993:00:02.0: 0.000 Gb/s available PCIe bandwidth, limited by Unknown speed x0 link at 7993:00:02.0 (capable of 63.008 Gb/s with 8 GT/s x8 link) Aug 24 21:45:20.172409 test-b1 kernel: pci 7993:00:02.0: BAR 0: assigned [mem 0xfe0000000-0xfe00fffff 64bit pref] Aug 24 21:45:20.180424 test-b1 systemd[1]: Found device /dev/ttyS0. Aug 24 21:45:20.254409 test-b1 systemd-udevd[468]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 24 21:45:20.257362 test-b1 systemd[1]: Found device /sys/devices/virtual/misc/vmbus!hv_kvp. Aug 24 21:45:20.263675 test-b1 systemd[1]: Started Hyper-V KVP Protocol Daemon. Aug 24 21:45:20.267231 test-b1 systemd[1]: Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch. Aug 24 21:45:20.276126 test-b1 kernel: RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer Aug 24 21:45:20.349158 test-b1 KVP[491]: KVP starting; pid is:491 Aug 24 21:45:20.353700 test-b1 KVP[491]: KVP LIC Version: 3.1 Aug 24 21:45:20.356764 test-b1 kernel: hv_utils: KVP IC version 4.0 Aug 24 21:45:20.416747 test-b1 kernel: mlx5_core 7993:00:02.0: firmware version: 14.25.8100 Aug 24 21:45:20.428738 test-b1 kernel: mlx5_core 7993:00:02.0: handle_hca_cap:540:(pid 7): log_max_qp value in current profile is 18, changing it to HCA capability limit (12) Aug 24 21:45:20.526027 test-b1 systemd[1]: Found device Virtual_Disk UEFI. Aug 24 21:45:20.533584 test-b1 systemd[1]: Mounting /boot/efi... Aug 24 21:45:20.555666 test-b1 systemd[1]: Mounted /boot/efi. Aug 24 21:45:20.558293 test-b1 systemd[1]: Reached target Local File Systems. Aug 24 21:45:20.563461 test-b1 systemd[1]: Starting Set console font and keymap... Aug 24 21:45:20.568293 test-b1 systemd[1]: Starting Tell Plymouth To Write Out Runtime Data... Aug 24 21:45:20.581109 test-b1 systemd[1]: Starting Create Volatile Files and Directories... Aug 24 21:45:20.594280 test-b1 systemd[1]: Starting AppArmor initialization... Aug 24 21:45:20.605666 test-b1 systemd[1]: Starting ebtables ruleset management... Aug 24 21:45:20.613324 test-b1 systemd[1]: Started Set console font and keymap. Aug 24 21:45:20.623890 test-b1 systemd[1]: Started Tell Plymouth To Write Out Runtime Data. Aug 24 21:45:20.631991 test-b1 systemd[1]: Started Create Volatile Files and Directories. Aug 24 21:45:20.652737 test-b1 kernel: mlx5_core 7993:00:02.0: MLX5E: StrdRq(0) RqSz(1024) StrdSz(256) RxCqeCmprss(0) Aug 24 21:45:20.659748 test-b1 systemd[1]: Found device Virtual_Disk 1. Aug 24 21:45:20.674619 test-b1 systemd[1]: Starting File System Check on /dev/disk/cloud/azure_resource-part1... Aug 24 21:45:20.680254 test-b1 systemd[1]: Starting Update UTMP about System Boot/Shutdown... Aug 24 21:45:20.685590 test-b1 systemd[1]: Starting Network Time Synchronization... Aug 24 21:45:20.690713 test-b1 systemd[1]: Started File System Check Daemon to report status. Aug 24 21:45:20.706951 test-b1 apparmor[608]: * Starting AppArmor profiles Aug 24 21:45:20.710636 test-b1 systemd[1]: Started Update UTMP about System Boot/Shutdown. Aug 24 21:45:20.757719 test-b1 systemd[1]: Started ebtables ruleset management. Aug 24 21:45:20.779685 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: VF registering: eth1 Aug 24 21:45:20.780292 test-b1 kernel: mlx5_core 7993:00:02.0 eth1: joined to eth0 Aug 24 21:45:20.795817 test-b1 systemd-udevd[462]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable. Aug 24 21:45:20.796745 test-b1 kernel: mlx5_core 7993:00:02.0 rename3: renamed from eth1 Aug 24 21:45:20.812758 test-b1 kernel: mlx5_ib: Mellanox Connect-IB Infiniband driver v5.0-0 Aug 24 21:45:20.860076 test-b1 systemd-fsck[621]: /dev/sda1: clean, 12/917504 files, 84229/3669744 blocks Aug 24 21:45:20.862133 test-b1 systemd[1]: Started File System Check on /dev/disk/cloud/azure_resource-part1. Aug 24 21:45:20.875000 test-b1 audit[680]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default" pid=680 comm="apparmor_parser" Aug 24 21:45:20.875000 test-b1 audit[680]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-cgns" pid=680 comm="apparmor_parser" Aug 24 21:45:20.875000 test-b1 audit[680]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-mounting" pid=680 comm="apparmor_parser" Aug 24 21:45:20.875000 test-b1 audit[680]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-nesting" pid=680 comm="apparmor_parser" Aug 24 21:45:20.880847 test-b1 kernel: audit: type=1400 audit(1598305520.875:2): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default" pid=680 comm="apparmor_parser" Aug 24 21:45:20.880900 test-b1 kernel: audit: type=1400 audit(1598305520.875:3): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-cgns" pid=680 comm="apparmor_parser" Aug 24 21:45:20.880922 test-b1 kernel: audit: type=1400 audit(1598305520.875:4): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-mounting" pid=680 comm="apparmor_parser" Aug 24 21:45:20.880956 test-b1 kernel: audit: type=1400 audit(1598305520.875:5): apparmor="STATUS" operation="profile_load" profile="unconfined" name="lxc-container-default-with-nesting" pid=680 comm="apparmor_parser" Aug 24 21:45:20.882245 test-b1 systemd[1]: Started Network Time Synchronization. Aug 24 21:45:20.883000 test-b1 audit[681]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=681 comm="apparmor_parser" Aug 24 21:45:20.883000 test-b1 audit[681]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=681 comm="apparmor_parser" Aug 24 21:45:20.883000 test-b1 audit[681]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=681 comm="apparmor_parser" Aug 24 21:45:20.883000 test-b1 audit[681]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=681 comm="apparmor_parser" Aug 24 21:45:20.888181 test-b1 systemd[1]: Reached target System Time Synchronized. Aug 24 21:45:20.888750 test-b1 kernel: audit: type=1400 audit(1598305520.883:6): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/sbin/dhclient" pid=681 comm="apparmor_parser" Aug 24 21:45:20.888780 test-b1 kernel: audit: type=1400 audit(1598305520.883:7): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=681 comm="apparmor_parser" Aug 24 21:45:20.888859 test-b1 kernel: audit: type=1400 audit(1598305520.883:8): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-helper" pid=681 comm="apparmor_parser" Aug 24 21:45:20.888878 test-b1 kernel: audit: type=1400 audit(1598305520.883:9): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/connman/scripts/dhclient-script" pid=681 comm="apparmor_parser" Aug 24 21:45:20.891000 test-b1 audit[683]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/lxc-start" pid=683 comm="apparmor_parser" Aug 24 21:45:20.891000 test-b1 audit[684]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=684 comm="apparmor_parser" Aug 24 21:45:20.891000 test-b1 audit[684]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_filter" pid=684 comm="apparmor_parser" Aug 24 21:45:20.891000 test-b1 audit[684]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="man_groff" pid=684 comm="apparmor_parser" Aug 24 21:45:20.895976 test-b1 apparmor[608]: Skipping profile in /etc/apparmor.d/disable: usr.sbin.rsyslogd Aug 24 21:45:20.896742 test-b1 kernel: audit: type=1400 audit(1598305520.891:10): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/lxc-start" pid=683 comm="apparmor_parser" Aug 24 21:45:20.896784 test-b1 kernel: audit: type=1400 audit(1598305520.891:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/bin/man" pid=684 comm="apparmor_parser" Aug 24 21:45:20.895000 test-b1 audit[685]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine" pid=685 comm="apparmor_parser" Aug 24 21:45:20.895000 test-b1 audit[685]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/snapd/snap-confine//mount-namespace-capture-helper" pid=685 comm="apparmor_parser" Aug 24 21:45:20.895000 test-b1 audit[687]: AVC apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/sbin/tcpdump" pid=687 comm="apparmor_parser" Aug 24 21:45:20.899370 test-b1 apparmor[608]: ...done. Aug 24 21:45:20.900001 test-b1 systemd[1]: Started AppArmor initialization. Aug 24 21:45:20.904553 test-b1 systemd[1]: Starting Load AppArmor profiles managed internally by snapd... Aug 24 21:45:20.909934 test-b1 systemd[1]: Starting Initial cloud-init job (pre-networking)... Aug 24 21:45:20.916685 test-b1 sh[689]: + [ -e /var/lib/cloud/instance/obj.pkl ] Aug 24 21:45:20.920659 test-b1 sh[689]: + echo cleaning persistent cloud-init object Aug 24 21:45:20.920659 test-b1 sh[689]: cleaning persistent cloud-init object Aug 24 21:45:20.920659 test-b1 sh[689]: + rm /var/lib/cloud/instance/obj.pkl Aug 24 21:45:20.933389 test-b1 snapd-apparmor[688]: find: ‘/var/lib/snapd/apparmor/profiles/’: No such file or directory Aug 24 21:45:20.934796 test-b1 sh[689]: + exit 0 Aug 24 21:45:20.934611 test-b1 systemd[1]: Started Load AppArmor profiles managed internally by snapd. Aug 24 21:46:08.192289 test-b1 kernel: hv_balloon: Max. dynamic memory size: 7168 MB Aug 24 21:46:21.388414 test-b1 systemd-udevd[455]: seq 3995 '/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A03:00/device:07/VMBUS:01/11a0f8fe-7993-499d-b2a2-ce823de97264/pci7993:00/7993:00:02.0/net/eth1' is taking a long time Aug 24 21:46:51.164691 test-b1 systemd-udevd[462]: error changing net interface name 'eth1' to 'eth0': File exists Aug 24 21:46:51.164747 test-b1 systemd-udevd[462]: could not rename interface '3' from 'eth1' to 'eth0': File exists Aug 24 21:46:51.236746 test-b1 kernel: mlx5_core 7993:00:02.0 rename3: Link up Aug 24 21:46:51.237044 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: Data path switched to VF: rename3 Aug 24 21:46:51.240753 test-b1 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready Aug 24 21:46:51.250954 test-b1 dhclient[727]: Internet Systems Consortium DHCP Client 4.3.5 Aug 24 21:46:51.250976 test-b1 dhclient[727]: Copyright 2004-2016 Internet Systems Consortium. Aug 24 21:46:51.250982 test-b1 dhclient[727]: All rights reserved. Aug 24 21:46:51.250988 test-b1 dhclient[727]: For info, please visit https://www.isc.org/software/dhcp/ Aug 24 21:46:51.250993 test-b1 dhclient[727]: Aug 24 21:46:51.269172 test-b1 dhclient[727]: Listening on LPF/eth0/00:0d:3a:03:44:ad Aug 24 21:46:51.269328 test-b1 dhclient[727]: Sending on LPF/eth0/00:0d:3a:03:44:ad Aug 24 21:46:51.269452 test-b1 dhclient[727]: Sending on Socket/fallback Aug 24 21:46:51.269569 test-b1 dhclient[727]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x586b967e) Aug 24 21:46:51.286340 test-b1 dhclient[727]: DHCPREQUEST of 10.1.0.4 on eth0 to 255.255.255.255 port 67 (xid=0x7e966b58) Aug 24 21:46:51.286488 test-b1 dhclient[727]: DHCPOFFER of 10.1.0.4 from 168.63.129.16 Aug 24 21:46:51.301772 test-b1 dhclient[727]: DHCPACK of 10.1.0.4 from 168.63.129.16 Aug 24 21:46:51.309692 test-b1 dhclient[727]: bound to 10.1.0.4 -- renewal in 4294967295 seconds. Aug 24 21:46:51.396770 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: Data path switched from VF: rename3 Aug 24 21:46:51.784773 test-b1 kernel: mlx5_core 7993:00:02.0 rename3: Link up Aug 24 21:46:51.785340 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: Data path switched to VF: rename3 Aug 24 21:46:51.791605 test-b1 dhclient[753]: Internet Systems Consortium DHCP Client 4.3.5 Aug 24 21:46:51.791628 test-b1 dhclient[753]: Copyright 2004-2016 Internet Systems Consortium. Aug 24 21:46:51.791634 test-b1 dhclient[753]: All rights reserved. Aug 24 21:46:51.791639 test-b1 dhclient[753]: For info, please visit https://www.isc.org/software/dhcp/ Aug 24 21:46:51.791644 test-b1 dhclient[753]: Aug 24 21:46:51.813089 test-b1 dhclient[753]: Listening on LPF/eth0/00:0d:3a:03:44:ad Aug 24 21:46:51.813136 test-b1 dhclient[753]: Sending on LPF/eth0/00:0d:3a:03:44:ad Aug 24 21:46:51.813202 test-b1 dhclient[753]: Sending on Socket/fallback Aug 24 21:46:51.813252 test-b1 dhclient[753]: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 3 (xid=0x7a37ce66) Aug 24 21:46:51.817506 test-b1 dhclient[753]: DHCPREQUEST of 10.1.0.4 on eth0 to 255.255.255.255 port 67 (xid=0x66ce377a) Aug 24 21:46:51.817565 test-b1 dhclient[753]: DHCPOFFER of 10.1.0.4 from 168.63.129.16 Aug 24 21:46:51.833326 test-b1 dhclient[753]: DHCPACK of 10.1.0.4 from 168.63.129.16 Aug 24 21:46:51.855386 test-b1 dhclient[753]: bound to 10.1.0.4 -- renewal in 4294967295 seconds. Aug 24 21:46:51.936767 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: Data path switched from VF: rename3 Aug 24 21:46:52.111581 test-b1 cloud-init[695]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'init-local' at Mon, 24 Aug 2020 21:45:21 +0000. Up 9.80 seconds. Aug 24 21:46:52.172565 test-b1 systemd[1]: Started Initial cloud-init job (pre-networking). Aug 24 21:46:52.176394 test-b1 systemd[1]: Reached target Network (Pre). Aug 24 21:46:52.180511 test-b1 systemd[1]: Starting Network Service... Aug 24 21:46:52.211190 test-b1 systemd-networkd[779]: Enumeration completed Aug 24 21:46:52.211263 test-b1 systemd-networkd[779]: rename3: Interface name change detected, rename3 has been renamed to eth1. Aug 24 21:46:52.211299 test-b1 systemd[1]: Started Network Service. Aug 24 21:46:52.211528 test-b1 systemd-networkd[779]: eth1: Interface name change detected, eth1 has been renamed to rename3. Aug 24 21:46:52.211570 test-b1 systemd-networkd[779]: rename3: Link UP Aug 24 21:46:52.211666 test-b1 systemd-networkd[779]: eth0: Link UP Aug 24 21:46:52.211825 test-b1 systemd-networkd[779]: eth0: Gained carrier Aug 24 21:46:52.211927 test-b1 systemd-networkd[779]: rename3: Gained carrier Aug 24 21:46:52.212355 test-b1 systemd-networkd[779]: rename3: Link DOWN Aug 24 21:46:52.212359 test-b1 systemd-networkd[779]: rename3: Lost carrier Aug 24 21:46:52.212451 test-b1 systemd-networkd[779]: eth0: Link DOWN Aug 24 21:46:52.212455 test-b1 systemd-networkd[779]: eth0: Lost carrier Aug 24 21:46:52.212596 test-b1 systemd-networkd[779]: eth0: Removing non-existent address: fe80::20d:3aff:fe03:44ad/64 (valid forever), ignoring Aug 24 21:46:52.212680 test-b1 systemd-networkd[779]: rename3: Link UP Aug 24 21:46:52.212688 test-b1 systemd-networkd[779]: rename3: Gained carrier Aug 24 21:46:52.212795 test-b1 systemd-networkd[779]: eth0: Link UP Aug 24 21:46:52.212799 test-b1 systemd-networkd[779]: eth0: Gained carrier Aug 24 21:46:52.213276 test-b1 systemd-networkd[779]: rename3: Link DOWN Aug 24 21:46:52.213280 test-b1 systemd-networkd[779]: rename3: Lost carrier Aug 24 21:46:52.213372 test-b1 systemd-networkd[779]: eth0: Link DOWN Aug 24 21:46:52.213375 test-b1 systemd-networkd[779]: eth0: Lost carrier Aug 24 21:46:52.213516 test-b1 systemd-networkd[779]: eth0: Removing non-existent address: fe80::20d:3aff:fe03:44ad/64 (valid forever), ignoring Aug 24 21:46:52.214119 test-b1 systemd-networkd[779]: eth0: IPv6 successfully enabled Aug 24 21:46:52.214426 test-b1 systemd-networkd[779]: rename3: Link is not managed by us Aug 24 21:46:52.214431 test-b1 systemd-networkd[779]: lo: Link is not managed by us Aug 24 21:46:52.219217 test-b1 systemd[1]: Starting Network Name Resolution... Aug 24 21:46:52.227561 test-b1 systemd[1]: Starting Wait for Network to be Configured... Aug 24 21:46:52.250239 test-b1 systemd-resolved[804]: Positive Trust Anchors: Aug 24 21:46:52.250309 test-b1 systemd-resolved[804]: . IN DS 19036 8 2 49aac11d7b6f6446702e54a1607371607a1a41855200fd2ce1cdde32f24e8fb5 Aug 24 21:46:52.250314 test-b1 systemd-resolved[804]: . IN DS 20326 8 2 e06d44b80b8f1d39a95c0b0d7c65d08458e880409bbc683457104237c7f8ec8d Aug 24 21:46:52.250343 test-b1 systemd-resolved[804]: Negative trust anchors: 10.in-addr.arpa 16.172.in-addr.arpa 17.172.in-addr.arpa 18.172.in-addr.arpa 19.172.in-addr.arpa 20.172.in-addr.arpa 21.172.in-addr.arpa 22.172.in-addr.arpa 23.172.in-addr.arpa 24.172.in-addr.arpa 25.172.in-addr.arpa 26.172.in-addr.arpa 27.172.in-addr.arpa 28.172.in-addr.arpa 29.172.in-addr.arpa 30.172.in-addr.arpa 31.172.in-addr.arpa 168.192.in-addr.arpa d.f.ip6.arpa corp home internal intranet lan local private test Aug 24 21:46:52.251157 test-b1 systemd-resolved[804]: Using system hostname 'test-b1'. Aug 24 21:46:52.280371 test-b1 systemd-networkd[779]: rename3: Link UP Aug 24 21:46:52.280948 test-b1 kernel: mlx5_core 7993:00:02.0 rename3: Link up Aug 24 21:46:52.281344 test-b1 kernel: hv_netvsc 000d3a03-44ad-000d-3a03-44ad000d3a03 eth0: Data path switched to VF: rename3 Aug 24 21:46:52.280390 test-b1 systemd-networkd[779]: rename3: Gained carrier Aug 24 21:46:52.280564 test-b1 systemd-networkd[779]: eth0: Link UP Aug 24 21:46:52.282361 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.282634 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.282662 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.282686 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.282708 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.282731 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:52.284671 test-b1 systemd[1]: Started Network Name Resolution. Aug 24 21:46:52.292056 test-b1 systemd[1]: Reached target Network. Aug 24 21:46:52.297584 test-b1 systemd[1]: Reached target Host and Network Name Lookups. Aug 24 21:46:52.302486 test-b1 systemd-networkd[779]: eth0: Gained carrier Aug 24 21:46:52.303486 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:53.864712 test-b1 systemd-networkd[779]: eth0: DHCPv4 address 10.1.0.4/24 via 10.1.0.1 Aug 24 21:46:53.866186 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:53.867543 test-b1 systemd-timesyncd[625]: Network configuration changed, trying to establish connection. Aug 24 21:46:53.867804 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:53.992965 test-b1 systemd-networkd[779]: eth0: Gained IPv6LL Aug 24 21:46:53.993024 test-b1 systemd-networkd[779]: eth0: Configured Aug 24 21:46:53.993745 test-b1 systemd-timesyncd[625]: Network configuration changed, trying to establish connection. Aug 24 21:46:53.994236 test-b1 systemd-networkd-wait-online[806]: ignoring: lo Aug 24 21:46:53.994247 test-b1 systemd-networkd-wait-online[806]: managing: eth0 Aug 24 21:46:53.995936 test-b1 systemd[1]: Started Wait for Network to be Configured. Aug 24 21:46:54.002233 test-b1 systemd[1]: Starting Initial cloud-init job (metadata service crawler)... Aug 24 21:46:54.927720 test-b1 cloud-init[823]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'init' at Mon, 24 Aug 2020 21:46:54 +0000. Up 102.61 seconds. Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +++++++++++++++++++++++++++++++++++++++Net device info+++++++++++++++++++++++++++++++++++++++ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +---------+------+-----------------------------+---------------+--------+-------------------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | Device | Up | Address | Mask | Scope | Hw-Address | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +---------+------+-----------------------------+---------------+--------+-------------------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | eth0 | True | 10.1.0.4 | 255.255.255.0 | global | 00:0d:3a:03:44:ad | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | eth0 | True | fe80::20d:3aff:fe03:44ad/64 | . | link | 00:0d:3a:03:44:ad | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | lo | True | 127.0.0.1 | 255.0.0.0 | host | . | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | lo | True | ::1/128 | . | host | . | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | rename3 | True | . | . | . | 00:0d:3a:03:44:ad | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +---------+------+-----------------------------+---------------+--------+-------------------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: ++++++++++++++++++++++++++++++Route IPv4 info+++++++++++++++++++++++++++++++ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +-------+-----------------+----------+-----------------+-----------+-------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | Route | Destination | Gateway | Genmask | Interface | Flags | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +-------+-----------------+----------+-----------------+-----------+-------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | 0 | 0.0.0.0 | 10.1.0.1 | 0.0.0.0 | eth0 | UG | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | 1 | 10.1.0.0 | 0.0.0.0 | 255.255.255.0 | eth0 | U | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | 2 | 168.63.129.16 | 10.1.0.1 | 255.255.255.255 | eth0 | UGH | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: | 3 | 169.254.169.254 | 10.1.0.1 | 255.255.255.255 | eth0 | UGH | Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +-------+-----------------+----------+-----------------+-----------+-------+ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +++++++++++++++++++Route IPv6 info+++++++++++++++++++ Aug 24 21:46:54.927720 test-b1 cloud-init[823]: ci-info: +-------+-------------+---------+-----------+-------+ Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: | Route | Destination | Gateway | Interface | Flags | Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: +-------+-------------+---------+-----------+-------+ Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: | 1 | fe80::/64 | :: | eth0 | U | Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: | 3 | local | :: | eth0 | U | Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: | 4 | ff00::/8 | :: | eth0 | U | Aug 24 21:46:55.076139 test-b1 cloud-init[823]: ci-info: +-------+-------------+---------+-----------+-------+ Aug 24 21:46:55.375932 test-b1 systemd[1]: Started Initial cloud-init job (metadata service crawler). Aug 24 21:46:55.382345 test-b1 systemd[1]: Reached target Cloud-config availability. Aug 24 21:46:55.388303 test-b1 systemd[1]: Mounting /mnt... Aug 24 21:46:55.390280 test-b1 systemd[1]: Reached target System Initialization. Aug 24 21:46:55.393719 test-b1 systemd[1]: Listening on UUID daemon activation socket. Aug 24 21:46:55.401876 test-b1 systemd[1]: Listening on Open-iSCSI iscsid Socket. Aug 24 21:46:55.412714 test-b1 systemd[1]: Started Message of the Day. Aug 24 21:46:55.420015 test-b1 systemd[1]: Starting LXD - unix socket. Aug 24 21:46:55.422979 test-b1 systemd[1]: Listening on D-Bus System Message Bus Socket. Aug 24 21:46:55.427282 test-b1 systemd[1]: Started ACPI Events Check. Aug 24 21:46:55.430006 test-b1 systemd[1]: Started Discard unused blocks once a week. Aug 24 21:46:55.433449 test-b1 systemd[1]: Reached target Paths. Aug 24 21:46:55.435836 test-b1 systemd[1]: Started Daily apt download activities. Aug 24 21:46:55.439000 test-b1 systemd[1]: Started Daily apt upgrade and clean activities. Aug 24 21:46:55.442751 test-b1 systemd[1]: Listening on ACPID Listen Socket. Aug 24 21:46:55.446988 test-b1 systemd[1]: Starting Socket activation for snappy daemon. Aug 24 21:46:55.448789 test-b1 kernel: EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null) Aug 24 21:46:55.450112 test-b1 systemd[1]: Started Daily Cleanup of Temporary Directories. Aug 24 21:46:55.453461 test-b1 systemd[1]: Reached target Timers. Aug 24 21:46:55.455729 test-b1 systemd[1]: Reached target Network is Online. Aug 24 21:46:55.460294 test-b1 systemd[1]: Starting Availability of block devices... Aug 24 21:46:55.463309 test-b1 systemd[1]: Reached target Remote File Systems (Pre). Aug 24 21:46:55.466459 test-b1 systemd[1]: Reached target Remote File Systems. Aug 24 21:46:55.470653 test-b1 systemd[1]: Mounted /mnt. Aug 24 21:46:55.472999 test-b1 systemd[1]: Listening on LXD - unix socket. Aug 24 21:46:55.475894 test-b1 systemd[1]: Listening on Socket activation for snappy daemon. Aug 24 21:46:55.479957 test-b1 systemd[1]: Started Availability of block devices. Aug 24 21:46:55.483044 test-b1 systemd[1]: Reached target Sockets. Aug 24 21:46:55.485236 test-b1 systemd[1]: Reached target Basic System. Aug 24 21:46:55.489497 test-b1 systemd[1]: Started Regular background program processing daemon. Aug 24 21:46:55.495671 test-b1 cron[949]: (CRON) INFO (pidfile fd = 3) Aug 24 21:46:55.498233 test-b1 systemd[1]: Started D-Bus System Message Bus. Aug 24 21:46:55.499130 test-b1 cron[949]: (CRON) INFO (Running @reboot jobs) Aug 24 21:46:55.524057 test-b1 dbus-daemon[954]: [system] AppArmor D-Bus mediation is enabled Aug 24 21:46:55.527574 test-b1 systemd[1]: Started Hyper-V VSS Protocol Daemon. Aug 24 21:46:55.533790 test-b1 hv_vss_daemon[971]: Hyper-V VSS: VSS starting; pid is:971 Aug 24 21:46:55.533854 test-b1 hv_vss_daemon[971]: Hyper-V VSS: VSS: kernel module version: 129 Aug 24 21:46:55.540889 test-b1 kernel: hv_utils: VSS: userspace daemon ver. 129 connected Aug 24 21:46:55.536465 test-b1 systemd[1]: Started Azure Linux Agent. Aug 24 21:46:55.546296 test-b1 systemd[1]: Starting LSB: automatic crash report generation... Aug 24 21:46:55.560988 test-b1 systemd[1]: Starting LSB: Record successful boot for GRUB... Aug 24 21:46:55.573242 test-b1 systemd[1]: Starting Permit User Sessions... Aug 24 21:46:55.590268 test-b1 systemd[1]: Starting Login Service... Aug 24 21:46:55.595665 test-b1 systemd[1]: Started irqbalance daemon. Aug 24 21:46:55.607324 test-b1 systemd[1]: Starting Dispatcher daemon for systemd-networkd... Aug 24 21:46:55.613172 test-b1 systemd-logind[1003]: New seat seat0. Aug 24 21:46:55.613872 test-b1 systemd-logind[1003]: Watching system buttons on /dev/input/event0 (Power Button) Aug 24 21:46:55.614544 test-b1 systemd-logind[1003]: Watching system buttons on /dev/input/event3 (AT Translated Set 2 keyboard) Aug 24 21:46:55.614859 test-b1 systemd-logind[1003]: Watching system buttons on /dev/input/event1 (AT Translated Set 2 keyboard) Aug 24 21:46:55.618079 test-b1 systemd[1]: Started Hyper-V File Copy Protocol Daemon. Aug 24 21:46:55.630857 test-b1 systemd[1]: Started Deferred execution scheduler. Aug 24 21:46:55.639336 test-b1 HV_FCOPY[1007]: starting; pid is:1007 Aug 24 21:46:55.639871 test-b1 HV_FCOPY[1007]: open /dev/vmbus/hv_fcopy failed; error: 2 No such file or directory Aug 24 21:46:55.642571 test-b1 systemd[1]: Started FUSE filesystem for LXC. Aug 24 21:46:55.651084 test-b1 systemd[1]: Starting Accounts Service... Aug 24 21:46:55.656166 test-b1 lxcfs[1011]: mount namespace: 5 Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: hierarchies: Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 0: fd: 6: hugetlb Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 1: fd: 7: perf_event Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 2: fd: 8: cpu,cpuacct Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 3: fd: 9: pids Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 4: fd: 10: devices Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 5: fd: 11: rdma Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 6: fd: 12: memory Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 7: fd: 13: freezer Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 8: fd: 14: net_cls,net_prio Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 9: fd: 15: cpuset Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 10: fd: 16: blkio Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 11: fd: 17: name=systemd Aug 24 21:46:55.656378 test-b1 lxcfs[1011]: 12: fd: 18: unified Aug 24 21:46:55.656769 test-b1 kernel: new mount options do not match the existing superblock, will be ignored Aug 24 21:46:55.659307 test-b1 systemd[1]: Starting Snap Daemon... Aug 24 21:46:55.665742 test-b1 systemd[1]: Starting OpenBSD Secure Shell server... Aug 24 21:46:55.672445 test-b1 systemd[1]: Starting System Logging Service... Aug 24 21:46:55.678800 test-b1 systemd[1]: Starting LXD - container startup/shutdown... Aug 24 21:46:55.687974 test-b1 systemd[1]: Started Permit User Sessions. Aug 24 21:46:55.693498 test-b1 systemd[1]: hv-fcopy-daemon.service: Main process exited, code=exited, status=1/FAILURE Aug 24 21:46:55.693675 test-b1 systemd[1]: hv-fcopy-daemon.service: Failed with result 'exit-code'. Aug 24 21:46:55.702914 test-b1 systemd[1]: Started Login Service. Aug 24 21:46:55.705940 test-b1 grub-common[986]: * Recording successful boot for GRUB Aug 24 21:46:55.723047 test-b1 apport[983]: * Starting automatic crash report generation: apport Aug 24 21:46:55.716904 test-b1 systemd[1]: Started Unattended Upgrades Shutdown. Aug 24 21:46:55.716715 test-b1 dbus-daemon[954]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.4' (uid=0 pid=1012 comm="/usr/lib/accountsservice/accounts-daemon " label="unconfined") Aug 24 21:46:55.726327 test-b1 systemd[1]: Starting Hold until boot process finishes up... Aug 24 21:46:55.736585 test-b1 systemd[1]: Starting Terminate Plymouth Boot Screen... Aug 24 21:46:55.743231 test-b1 systemd[1]: Started Hold until boot process finishes up. Aug 24 21:46:55.756397 test-b1 systemd[1]: Started Terminate Plymouth Boot Screen. Aug 24 21:46:55.768945 test-b1 systemd[1]: Starting Authorization Manager... Aug 24 21:46:55.773046 test-b1 apport[983]: ...done. Aug 24 21:46:55.777808 test-b1 systemd[1]: Starting Set console scheme... Aug 24 21:46:55.784608 test-b1 systemd[1]: Started Serial Getty on ttyS0. Aug 24 21:46:55.796656 test-b1 systemd[1]: Started LSB: automatic crash report generation. Aug 24 21:46:55.813374 test-b1 systemd[1]: Started Set console scheme. Aug 24 21:46:55.822617 test-b1 systemd[1]: Created slice system-getty.slice. Aug 24 21:46:55.830007 test-b1 systemd[1]: Started Getty on tty1. Aug 24 21:46:55.835809 test-b1 systemd[1]: Reached target Login Prompts. Aug 24 21:46:55.856038 test-b1 systemd[1]: Started System Logging Service. Aug 24 21:46:55.862474 test-b1 rsyslogd[1018]: imuxsock: Acquired UNIX socket '/run/systemd/journal/syslog' (fd 3) from systemd. [v8.32.0] Aug 24 21:46:55.862485 test-b1 rsyslogd[1018]: rsyslogd's groupid changed to 106 Aug 24 21:46:55.862488 test-b1 rsyslogd[1018]: rsyslogd's userid changed to 102 Aug 24 21:46:55.862491 test-b1 rsyslogd[1018]: [origin software="rsyslogd" swVersion="8.32.0" x-pid="1018" x-info="http://www.rsyslog.com"] start Aug 24 21:46:55.868686 test-b1 sshd[1041]: Server listening on 0.0.0.0 port 22. Aug 24 21:46:55.869076 test-b1 sshd[1041]: Server listening on :: port 22. Aug 24 21:46:55.869276 test-b1 systemd[1]: Started OpenBSD Secure Shell server. Aug 24 21:46:55.879041 test-b1 grub-common[986]: ...done. Aug 24 21:46:55.879794 test-b1 systemd[1]: Started LSB: Record successful boot for GRUB. Aug 24 21:46:55.899441 test-b1 polkitd[1034]: started daemon version 0.105 using authority implementation `local' version `0.105' Aug 24 21:46:55.900042 test-b1 dbus-daemon[954]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Aug 24 21:46:55.900157 test-b1 systemd[1]: Started Authorization Manager. Aug 24 21:46:55.913073 test-b1 accounts-daemon[1012]: started daemon version 0.6.45 Aug 24 21:46:55.913665 test-b1 systemd[1]: Started Accounts Service. Aug 24 21:46:56.007662 test-b1 networkd-dispatcher[1005]: No valid path found for iwconfig Aug 24 21:46:56.104383 test-b1 systemd[1]: Started Dispatcher daemon for systemd-networkd. Aug 24 21:46:56.213800 test-b1 snapd[1013]: AppArmor status: apparmor is enabled and all features are available Aug 24 21:46:56.310650 test-b1 python3[982]: 2020/08/24 21:46:56.310469 INFO Daemon Azure Linux Agent Version:2.2.45 Aug 24 21:46:56.318432 test-b1 python3[982]: 2020/08/24 21:46:56.318355 INFO Daemon OS: ubuntu 18.04 Aug 24 21:46:56.320710 test-b1 systemd[1]: Started LXD - container startup/shutdown. Aug 24 21:46:56.326089 test-b1 python3[982]: 2020/08/24 21:46:56.322094 INFO Daemon Python: 3.6.9 Aug 24 21:46:56.328397 test-b1 snapd[1013]: patch.go:64: Patching system state level 6 to sublevel 1... Aug 24 21:46:56.329275 test-b1 python3[982]: 2020/08/24 21:46:56.329233 INFO Daemon CGroups Status: The cgroup filesystem is ready to use Aug 24 21:46:56.341950 test-b1 snapd[1013]: patch.go:64: Patching system state level 6 to sublevel 2... Aug 24 21:46:56.343258 test-b1 python3[982]: 2020/08/24 21:46:56.343215 INFO Daemon Run daemon Aug 24 21:46:56.355326 test-b1 python3[982]: 2020/08/24 21:46:56.355228 INFO Daemon cloud-init is enabled: True Aug 24 21:46:56.359268 test-b1 snapd[1013]: patch.go:64: Patching system state level 6 to sublevel 3... Aug 24 21:46:56.361201 test-b1 python3[982]: 2020/08/24 21:46:56.361149 INFO Daemon Using cloud-init for provisioning Aug 24 21:46:56.366730 test-b1 python3[982]: 2020/08/24 21:46:56.366673 INFO Daemon Clean protocol Aug 24 21:46:56.371425 test-b1 python3[982]: 2020/08/24 21:46:56.371392 INFO Daemon Provisioning already completed, skipping. Aug 24 21:46:56.376699 test-b1 python3[982]: 2020/08/24 21:46:56.376651 INFO Daemon RDMA capabilities are not enabled, skipping Aug 24 21:46:56.387057 test-b1 python3[982]: 2020/08/24 21:46:56.387013 INFO Daemon Determined Agent WALinuxAgent-2.2.49.2 to be the latest agent Aug 24 21:46:56.391492 test-b1 snapd[1013]: daemon.go:343: started snapd/2.45.1+18.04.2 (series 16; classic) ubuntu/18.04 (amd64) linux/5.3.0-1035-azure. Aug 24 21:46:56.452225 test-b1 snapd[1013]: daemon.go:436: adjusting startup timeout by 30s (pessimistic estimate of 30s plus 5s per snap) Aug 24 21:46:56.472407 test-b1 systemd[1]: Started Snap Daemon. Aug 24 21:46:56.480503 test-b1 systemd[1]: Starting Wait until snapd is fully seeded... Aug 24 21:46:56.509541 test-b1 systemd[1]: Started Wait until snapd is fully seeded. Aug 24 21:46:56.519433 test-b1 systemd[1]: Starting Apply the settings specified in cloud-config... Aug 24 21:46:56.747836 test-b1 python3[982]: 2020-08-24T21:46:56.747715Z INFO ExtHandler ExtHandler Agent WALinuxAgent-2.2.49.2 is running as the goal state agent Aug 24 21:46:56.758863 test-b1 python3[982]: 2020-08-24T21:46:56.758814Z INFO ExtHandler ExtHandler Detect protocol endpoint Aug 24 21:46:56.763691 test-b1 python3[982]: 2020-08-24T21:46:56.763654Z INFO ExtHandler ExtHandler Clean protocol and wireserver endpoint Aug 24 21:46:56.769317 test-b1 python3[982]: 2020-08-24T21:46:56.769281Z INFO ExtHandler ExtHandler WireServer endpoint is not found. Rerun dhcp handler Aug 24 21:46:56.775581 test-b1 python3[982]: 2020-08-24T21:46:56.775547Z INFO ExtHandler ExtHandler Test for route to 168.63.129.16 Aug 24 21:46:56.780772 test-b1 python3[982]: 2020-08-24T21:46:56.780713Z INFO ExtHandler ExtHandler Route to 168.63.129.16 exists Aug 24 21:46:56.785867 test-b1 python3[982]: 2020-08-24T21:46:56.785803Z INFO ExtHandler ExtHandler Wire server endpoint:168.63.129.16 Aug 24 21:46:56.796641 test-b1 python3[982]: 2020-08-24T21:46:56.796603Z INFO ExtHandler ExtHandler Fabric preferred wire protocol version:2015-04-05 Aug 24 21:46:56.807763 test-b1 python3[982]: 2020-08-24T21:46:56.807741Z INFO ExtHandler ExtHandler Wire protocol version:2012-11-30 Aug 24 21:46:56.812798 test-b1 python3[982]: 2020-08-24T21:46:56.812699Z INFO ExtHandler ExtHandler Server preferred version:2015-04-05 Aug 24 21:46:57.061757 test-b1 python3[982]: 2020-08-24T21:46:57.061589Z INFO ExtHandler ExtHandler Initializing goal state during protocol detection Aug 24 21:46:57.069774 test-b1 cloud-init[1163]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'modules:config' at Mon, 24 Aug 2020 21:46:56 +0000. Up 105.19 seconds. Aug 24 21:46:57.081399 test-b1 python3[982]: 2020-08-24T21:46:57.081343Z INFO ExtHandler ExtHandler Fetching new goal state [incarnation 1 (force update)] Aug 24 21:46:57.135609 test-b1 systemd[1]: Started Apply the settings specified in cloud-config. Aug 24 21:46:57.138851 test-b1 python3[982]: 2020-08-24T21:46:57.138751Z INFO ExtHandler ExtHandler Certificate with thumbprint 459B82F0931029F080578C0556746D0627A95120 has no matching private key. Aug 24 21:46:57.145532 test-b1 python3[982]: 2020-08-24T21:46:57.145503Z INFO ExtHandler ExtHandler Fetch goal state completed Aug 24 21:46:57.156629 test-b1 systemd[1]: Starting Write warning to Azure ephemeral disk... Aug 24 21:46:57.163217 test-b1 python3[982]: 2020-08-24T21:46:57.163183Z INFO ExtHandler ExtHandler Distro: ubuntu-18.04; OSUtil: Ubuntu18OSUtil; AgentService: walinuxagent; Python: 3.6.9 Aug 24 21:46:57.177066 test-b1 python3[982]: 2020-08-24T21:46:57.177026Z INFO ExtHandler ExtHandler Start env monitor service. Aug 24 21:46:57.177413 test-b1 python3[982]: 2020-08-24T21:46:57.177382Z INFO MonitorHandler ExtHandler WireServer endpoint 168.63.129.16 read from file Aug 24 21:46:57.181862 test-b1 systemd[1]: Started Write warning to Azure ephemeral disk. Aug 24 21:46:57.184489 test-b1 python3[982]: 2020-08-24T21:46:57.184450Z INFO ExtHandler ExtHandler Configure routes Aug 24 21:46:57.186101 test-b1 python3[982]: 2020-08-24T21:46:57.186070Z INFO ExtHandler ExtHandler Gateway:None Aug 24 21:46:57.186887 test-b1 python3[982]: 2020-08-24T21:46:57.186860Z INFO MonitorHandler ExtHandler Wire server endpoint:168.63.129.16 Aug 24 21:46:57.188451 test-b1 python3[982]: 2020-08-24T21:46:57.188419Z INFO ExtHandler ExtHandler Routes:None Aug 24 21:46:57.200263 test-b1 python3[982]: 2020-08-24T21:46:57.200219Z INFO ExtHandler ExtHandler WALinuxAgent-2.2.49.2 running as process 1122 Aug 24 21:46:57.204028 test-b1 python3[982]: 2020-08-24T21:46:57.203830Z INFO EnvHandler ExtHandler WireServer endpoint 168.63.129.16 read from file Aug 24 21:46:57.205428 test-b1 python3[982]: 2020-08-24T21:46:57.205398Z INFO EnvHandler ExtHandler Wire server endpoint:168.63.129.16 Aug 24 21:46:57.215769 test-b1 python3[982]: 2020-08-24T21:46:57.215720Z INFO ExtHandler ExtHandler systemd version: systemd 237 Aug 24 21:46:57.215769 test-b1 python3[982]: +PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid Aug 24 21:46:57.222978 test-b1 python3[982]: 2020-08-24T21:46:57.222849Z INFO ExtHandler ExtHandler The CPU cgroup controller is mounted at /sys/fs/cgroup/cpu,cpuacct Aug 24 21:46:57.230655 test-b1 python3[982]: 2020-08-24T21:46:57.228229Z INFO ExtHandler ExtHandler The memory cgroup controller is mounted at /sys/fs/cgroup/memory Aug 24 21:46:57.241487 test-b1 python3[982]: 2020-08-24T21:46:57.241364Z WARNING ExtHandler ExtHandler cgroups v2 mounted at /sys/fs/cgroup/unified. Controllers: [] Aug 24 21:46:57.272803 test-b1 kernel: bpfilter: Loaded bpfilter_umh pid 1249 Aug 24 21:46:57.272848 test-b1 unknown: Started bpfilter Aug 24 21:46:57.274756 test-b1 systemd[1]: Reached target Multi-User System. Aug 24 21:46:57.278666 test-b1 systemd[1]: Reached target Graphical Interface. Aug 24 21:46:57.284484 test-b1 systemd[1]: Starting Update UTMP about System Runlevel Changes... Aug 24 21:46:57.291056 test-b1 systemd[1]: Starting Execute cloud user/final scripts... Aug 24 21:46:57.315528 test-b1 systemd[1]: Started Update UTMP about System Runlevel Changes. Aug 24 21:46:57.317628 test-b1 python3[982]: 2020-08-24T21:46:57.317473Z INFO ExtHandler ExtHandler CPUAccounting: no Aug 24 21:46:57.340776 test-b1 python3[982]: 2020-08-24T21:46:57.340700Z INFO ExtHandler ExtHandler MemoryAccounting: no Aug 24 21:46:57.346781 test-b1 python3[982]: 2020-08-24T21:46:57.346742Z INFO ExtHandler ExtHandler Started tracking cgroup: walinuxagent.service, path: /sys/fs/cgroup/cpu,cpuacct/system.slice/walinuxagent.service Aug 24 21:46:57.365904 test-b1 python3[982]: 2020-08-24T21:46:57.357056Z INFO ExtHandler ExtHandler Started tracking cgroup: walinuxagent.service, path: /sys/fs/cgroup/memory/system.slice/walinuxagent.service Aug 24 21:46:57.378603 test-b1 python3[982]: 2020-08-24T21:46:57.378551Z INFO ExtHandler ExtHandler Agent cgroups: CPU: /sys/fs/cgroup/cpu,cpuacct/system.slice/walinuxagent.service -- MEMORY: /sys/fs/cgroup/memory/system.slice/walinuxagent.service Aug 24 21:46:57.401919 test-b1 python3[982]: 2020-08-24T21:46:57.401863Z INFO ExtHandler ExtHandler Checking for agent updates (family: Prod) Aug 24 21:46:57.423617 test-b1 python3[982]: 2020-08-24T21:46:57.423508Z INFO EnvHandler ExtHandler Successfully added Azure fabric firewall rules Aug 24 21:46:57.450017 test-b1 python3[982]: 2020-08-24T21:46:57.449962Z INFO EnvHandler ExtHandler Firewall rules: Aug 24 21:46:57.450017 test-b1 python3[982]: Chain INPUT (policy ACCEPT 15 packets, 21334 bytes) Aug 24 21:46:57.450017 test-b1 python3[982]: pkts bytes target prot opt in out source destination Aug 24 21:46:57.450017 test-b1 python3[982]: Chain FORWARD (policy ACCEPT 0 packets, 0 bytes) Aug 24 21:46:57.450017 test-b1 python3[982]: pkts bytes target prot opt in out source destination Aug 24 21:46:57.450017 test-b1 python3[982]: Chain OUTPUT (policy ACCEPT 14 packets, 1478 bytes) Aug 24 21:46:57.450017 test-b1 python3[982]: pkts bytes target prot opt in out source destination Aug 24 21:46:57.450017 test-b1 python3[982]: 10 1115 ACCEPT tcp -- * * 0.0.0.0/0 168.63.129.16 owner UID match 0 Aug 24 21:46:57.450017 test-b1 python3[982]: 0 0 DROP tcp -- * * 0.0.0.0/0 168.63.129.16 ctstate INVALID,NEW Aug 24 21:46:57.474459 test-b1 python3[982]: 2020-08-24T21:46:57.474423Z INFO MonitorHandler ExtHandler Route table: [{"Iface": "eth0", "Destination": "0.0.0.0", "Gateway": "10.1.0.1", "Mask": "0.0.0.0", "Flags": "0x0003", "Metric": "100"},{"Iface": "eth0", "Destination": "10.1.0.0", "Gateway": "0.0.0.0", "Mask": "255.255.255.0", "Flags": "0x0001", "Metric": "0"},{"Iface": "eth0", "Destination": "168.63.129.16", "Gateway": "10.1.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "100"},{"Iface": "eth0", "Destination": "169.254.169.254", "Gateway": "10.1.0.1", "Mask": "255.255.255.255", "Flags": "0x0007", "Metric": "100"}] Aug 24 21:46:57.497581 test-b1 python3[982]: 2020-08-24T21:46:57.497544Z INFO EnvHandler ExtHandler Set block dev timeout: sdb with timeout: 300 Aug 24 21:46:57.538892 test-b1 python3[982]: 2020-08-24T21:46:57.538803Z INFO EnvHandler ExtHandler Set block dev timeout: sda with timeout: 300 Aug 24 21:46:57.545997 test-b1 python3[982]: 2020-08-24T21:46:57.545946Z INFO MonitorHandler ExtHandler Initial NIC state: [{ "name": "lo", "link": "<LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN mode DEFAULT group default qlen 1000\ link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00" }, { "name": "eth0", "link": "<BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc mq state UP mode DEFAULT group default qlen 1000\ link/ether 00:0d:3a:03:44:ad brd ff:ff:ff:ff:ff:ff" }, { "name": "rename3", "link": "<BROADCAST,MULTICAST,SLAVE,UP,LOWER_UP> mtu 1500 qdisc mq master eth0 state UP mode DEFAULT group default qlen 1000\ link/ether 00:0d:3a:03:44:ad brd ff:ff:ff:ff:ff:ff" }] Aug 24 21:46:57.590356 test-b1 python3[982]: 2020-08-24T21:46:57.590236Z INFO ExtHandler ExtHandler ProcessGoalState completed [incarnation 1; 141 ms] Aug 24 21:46:57.603345 test-b1 python3[982]: 2020-08-24T21:46:57.603286Z INFO ExtHandler ExtHandler [HEARTBEAT] Agent WALinuxAgent-2.2.49.2 is running as the goal state agent [DEBUG HeartbeatCounter: 1;HeartbeatId: 669F5DE7-5032-4718-8FB7-1BE69AF03538;DroppedPackets: 0;UpdateGSErrors: 0;AutoUpdate: 1] Aug 24 21:46:57.956285 test-b1 cloud-init[1255]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 running 'modules:final' at Mon, 24 Aug 2020 21:46:57 +0000. Up 106.08 seconds. Aug 24 21:46:57.956285 test-b1 cloud-init[1255]: Cloud-init v. 20.2-45-g5f7825e2-0ubuntu1~18.04.1 finished at Mon, 24 Aug 2020 21:46:57 +0000. Datasource DataSourceAzure [seed=/var/lib/waagent]. Up 106.19 seconds Aug 24 21:46:58.007483 test-b1 systemd[1]: Started Execute cloud user/final scripts. Aug 24 21:46:58.014046 test-b1 systemd[1]: Reached target Cloud-init target. Aug 24 21:46:58.028542 test-b1 systemd[1]: Startup finished in 7.357s (kernel) + 1min 38.919s (userspace) = 1min 46.277s. Aug 24 21:47:01.480699 test-b1 snapd[1013]: daemon.go:542: gracefully waiting for running hooks Aug 24 21:47:01.480699 test-b1 snapd[1013]: daemon.go:544: done waiting for running hooks Aug 24 21:47:01.481540 test-b1 snapd[1013]: daemon stop requested to wait for socket activation Aug 24 21:47:07.638606 test-b1 sshd[1361]: Accepted publickey for ubuntu from 24.9.64.41 port 36972 ssh2: RSA SHA256:Bo1uM2lRFE3Sc4gjrI3+J3b7LbNFemY3xIdjqX8hxmk Aug 24 21:47:07.641587 test-b1 sshd[1361]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0) Aug 24 21:47:07.649337 test-b1 systemd[1]: Created slice User Slice of ubuntu. Aug 24 21:47:07.653229 test-b1 systemd[1]: Starting User Manager for UID 1000... Aug 24 21:47:07.654874 test-b1 systemd[1]: Started Session 1 of user ubuntu. Aug 24 21:47:07.655597 test-b1 systemd-logind[1003]: New session 1 of user ubuntu. Aug 24 21:47:07.658098 test-b1 systemd[1374]: pam_unix(systemd-user:session): session opened for user ubuntu by (uid=0) Aug 24 21:47:07.698030 test-b1 systemd[1374]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Aug 24 21:47:07.698084 test-b1 systemd[1374]: Listening on GnuPG network certificate management daemon. Aug 24 21:47:07.698095 test-b1 systemd[1374]: Reached target Timers. Aug 24 21:47:07.698132 test-b1 systemd[1374]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Aug 24 21:47:07.698141 test-b1 systemd[1374]: Reached target Paths. Aug 24 21:47:07.698176 test-b1 systemd[1374]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 24 21:47:07.698213 test-b1 systemd[1374]: Listening on REST API socket for snapd user session agent. Aug 24 21:47:07.698247 test-b1 systemd[1374]: Listening on GnuPG cryptographic agent and passphrase cache. Aug 24 21:47:07.698272 test-b1 systemd[1374]: Reached target Sockets. Aug 24 21:47:07.698281 test-b1 systemd[1374]: Reached target Basic System. Aug 24 21:47:07.698373 test-b1 systemd[1]: Started User Manager for UID 1000. Aug 24 21:47:07.698563 test-b1 systemd[1374]: Reached target Default. Aug 24 21:47:07.698577 test-b1 systemd[1374]: Startup finished in 33ms. Aug 24 21:47:08.608286 test-b1 sshd[1371]: Accepted publickey for ubuntu from 24.9.64.41 port 36974 ssh2: RSA SHA256:Bo1uM2lRFE3Sc4gjrI3+J3b7LbNFemY3xIdjqX8hxmk Aug 24 21:47:08.610331 test-b1 sshd[1371]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0) Aug 24 21:47:08.612298 test-b1 systemd-logind[1003]: New session 3 of user ubuntu. Aug 24 21:47:08.612753 test-b1 systemd[1]: Started Session 3 of user ubuntu. Aug 24 21:47:14.294507 test-b1 sshd[1507]: Received disconnect from 24.9.64.41 port 36972:11: disconnected by user Aug 24 21:47:14.294589 test-b1 sshd[1507]: Disconnected from user ubuntu 24.9.64.41 port 36972 Aug 24 21:47:14.295394 test-b1 sshd[1361]: pam_unix(sshd:session): session closed for user ubuntu Aug 24 21:47:14.299193 test-b1 systemd-logind[1003]: Removed session 1. Aug 24 21:47:24.220951 test-b1 systemd-timesyncd[625]: Synchronized to time server 91.189.89.199:123 (ntp.ubuntu.com). Aug 24 21:51:08.448964 test-b1 sshd[1574]: Received disconnect from 24.9.64.41 port 36974:11: disconnected by user Aug 24 21:51:08.449043 test-b1 sshd[1574]: Disconnected from user ubuntu 24.9.64.41 port 36974 Aug 24 21:51:08.454190 test-b1 systemd-logind[1003]: Removed session 3. Aug 24 21:51:08.449701 test-b1 sshd[1371]: pam_unix(sshd:session): session closed for user ubuntu Aug 24 21:51:08.455004 test-b1 systemd[1]: Stopping User Manager for UID 1000... Aug 24 21:51:08.456949 test-b1 systemd[1374]: Stopped target Default. Aug 24 21:51:08.456971 test-b1 systemd[1374]: Stopped target Basic System. Aug 24 21:51:08.456985 test-b1 systemd[1374]: Stopped target Paths. Aug 24 21:51:08.456997 test-b1 systemd[1374]: Stopped target Timers. Aug 24 21:51:08.457008 test-b1 systemd[1374]: Stopped target Sockets. Aug 24 21:51:08.457111 test-b1 systemd[1374]: Closed GnuPG network certificate management daemon. Aug 24 21:51:08.457186 test-b1 systemd[1374]: Closed GnuPG cryptographic agent and passphrase cache. Aug 24 21:51:08.457260 test-b1 systemd[1374]: Closed GnuPG cryptographic agent (ssh-agent emulation). Aug 24 21:51:08.457332 test-b1 systemd[1374]: Closed GnuPG cryptographic agent and passphrase cache (restricted). Aug 24 21:51:08.457409 test-b1 systemd[1374]: Closed REST API socket for snapd user session agent. Aug 24 21:51:08.457481 test-b1 systemd[1374]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 24 21:51:08.457500 test-b1 systemd[1374]: Reached target Shutdown. Aug 24 21:51:08.458721 test-b1 systemd[1374]: Starting Exit the Session... Aug 24 21:51:08.461336 test-b1 systemd[1374]: Received SIGRTMIN+24 from PID 1683 (kill). Aug 24 21:51:08.464813 test-b1 systemd[1]: Stopped User Manager for UID 1000. Aug 24 21:51:08.465129 test-b1 systemd[1]: Removed slice User Slice of ubuntu. Aug 24 21:51:20.011723 test-b1 sshd[1684]: Accepted publickey for ubuntu from 24.9.64.41 port 37054 ssh2: RSA SHA256:Bo1uM2lRFE3Sc4gjrI3+J3b7LbNFemY3xIdjqX8hxmk Aug 24 21:51:20.013734 test-b1 sshd[1684]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0) Aug 24 21:51:20.020201 test-b1 systemd[1]: Created slice User Slice of ubuntu. Aug 24 21:51:20.023468 test-b1 systemd[1]: Starting User Manager for UID 1000... Aug 24 21:51:20.026592 test-b1 systemd[1686]: pam_unix(systemd-user:session): session opened for user ubuntu by (uid=0) Aug 24 21:51:20.033464 test-b1 systemd[1]: Started Session 4 of user ubuntu. Aug 24 21:51:20.033602 test-b1 systemd-logind[1003]: New session 4 of user ubuntu. Aug 24 21:51:20.055700 test-b1 systemd[1686]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Aug 24 21:51:20.055758 test-b1 systemd[1686]: Listening on GnuPG cryptographic agent and passphrase cache. Aug 24 21:51:20.055798 test-b1 systemd[1686]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 24 21:51:20.055809 test-b1 systemd[1686]: Reached target Paths. Aug 24 21:51:20.055846 test-b1 systemd[1686]: Listening on GnuPG network certificate management daemon. Aug 24 21:51:20.055884 test-b1 systemd[1686]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Aug 24 21:51:20.055895 test-b1 systemd[1686]: Reached target Timers. Aug 24 21:51:20.055932 test-b1 systemd[1686]: Listening on REST API socket for snapd user session agent. Aug 24 21:51:20.055942 test-b1 systemd[1686]: Reached target Sockets. Aug 24 21:51:20.055950 test-b1 systemd[1686]: Reached target Basic System. Aug 24 21:51:20.055983 test-b1 systemd[1686]: Reached target Default. Aug 24 21:51:20.055996 test-b1 systemd[1686]: Startup finished in 25ms. Aug 24 21:51:20.056042 test-b1 systemd[1]: Started User Manager for UID 1000. Aug 24 21:51:22.149968 test-b1 sshd[1762]: Received disconnect from 24.9.64.41 port 37054:11: disconnected by user Aug 24 21:51:22.150048 test-b1 sshd[1762]: Disconnected from user ubuntu 24.9.64.41 port 37054 Aug 24 21:51:22.150763 test-b1 sshd[1684]: pam_unix(sshd:session): session closed for user ubuntu Aug 24 21:51:22.154324 test-b1 systemd-logind[1003]: Removed session 4. Aug 24 21:51:22.155325 test-b1 systemd[1]: Stopping User Manager for UID 1000... Aug 24 21:51:22.156418 test-b1 systemd[1686]: Stopped target Default. Aug 24 21:51:22.156437 test-b1 systemd[1686]: Stopped target Basic System. Aug 24 21:51:22.156447 test-b1 systemd[1686]: Stopped target Timers. Aug 24 21:51:22.156454 test-b1 systemd[1686]: Stopped target Sockets. Aug 24 21:51:22.156523 test-b1 systemd[1686]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 24 21:51:22.156570 test-b1 systemd[1686]: Closed REST API socket for snapd user session agent. Aug 24 21:51:22.156578 test-b1 systemd[1686]: Stopped target Paths. Aug 24 21:51:22.156622 test-b1 systemd[1686]: Closed GnuPG network certificate management daemon. Aug 24 21:51:22.156666 test-b1 systemd[1686]: Closed GnuPG cryptographic agent and passphrase cache. Aug 24 21:51:22.156716 test-b1 systemd[1686]: Closed GnuPG cryptographic agent and passphrase cache (restricted). Aug 24 21:51:22.156773 test-b1 systemd[1686]: Closed GnuPG cryptographic agent (ssh-agent emulation). Aug 24 21:51:22.156786 test-b1 systemd[1686]: Reached target Shutdown. Aug 24 21:51:22.157640 test-b1 systemd[1686]: Starting Exit the Session... Aug 24 21:51:22.160624 test-b1 systemd[1686]: Received SIGRTMIN+24 from PID 1764 (kill). Aug 24 21:51:22.163253 test-b1 systemd[1]: Stopped User Manager for UID 1000. Aug 24 21:51:22.163577 test-b1 systemd[1]: Removed slice User Slice of ubuntu. Aug 24 21:52:49.922577 test-b1 sshd[1784]: Accepted publickey for ubuntu from 24.9.64.41 port 37082 ssh2: RSA SHA256:Bo1uM2lRFE3Sc4gjrI3+J3b7LbNFemY3xIdjqX8hxmk Aug 24 21:52:49.924559 test-b1 sshd[1784]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0) Aug 24 21:52:49.930788 test-b1 systemd[1]: Created slice User Slice of ubuntu. Aug 24 21:52:49.933418 test-b1 systemd[1]: Starting User Manager for UID 1000... Aug 24 21:52:49.936221 test-b1 systemd[1786]: pam_unix(systemd-user:session): session opened for user ubuntu by (uid=0) Aug 24 21:52:49.945624 test-b1 systemd[1]: Started Session 6 of user ubuntu. Aug 24 21:52:49.945954 test-b1 systemd-logind[1003]: New session 6 of user ubuntu. Aug 24 21:52:49.964986 test-b1 systemd[1786]: Reached target Paths. Aug 24 21:52:49.965054 test-b1 systemd[1786]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Aug 24 21:52:49.965098 test-b1 systemd[1786]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Aug 24 21:52:49.965138 test-b1 systemd[1786]: Listening on REST API socket for snapd user session agent. Aug 24 21:52:49.965176 test-b1 systemd[1786]: Listening on GnuPG network certificate management daemon. Aug 24 21:52:49.965213 test-b1 systemd[1786]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Aug 24 21:52:49.965225 test-b1 systemd[1786]: Reached target Timers. Aug 24 21:52:49.965261 test-b1 systemd[1786]: Listening on GnuPG cryptographic agent and passphrase cache. Aug 24 21:52:49.965270 test-b1 systemd[1786]: Reached target Sockets. Aug 24 21:52:49.965278 test-b1 systemd[1786]: Reached target Basic System. Aug 24 21:52:49.965305 test-b1 systemd[1786]: Reached target Default. Aug 24 21:52:49.965318 test-b1 systemd[1786]: Startup finished in 25ms. Aug 24 21:52:49.965930 test-b1 systemd[1]: Started User Manager for UID 1000.

Thanks. I think this is the right fix; I think we overlooked preventing network-v2 config from matching non-hyperv nics once we started crawling IMDS; It's possible that this was not noticed as there is a race between the kernel completes the SRIOV bond and when cloud-init starts to generate networking.

Let's confirm that IMDS does not include an SRIOV device (I don't think it will since it contains a duplicate mac of one of the hyperv nics).

For fallback, we need to update the blacklist to include mlx5-core (newer hardware). This is only important for Xenial (and non-netplan rendered targets) I believe those paths will ignore the mlx devices, but we should also ensure that the driver value is emitted in the udev rule (

blackboxsw · 2020-08-25T02:52:48Z

Confirmed IMDS doesn't surface both interfaces for config (see lines 38-58 of http://paste.ubuntu.com/p/CFjtY7JHm4/) That shows only one network interface represented through IMDS. since they share the same mac I'm going to say it isn't the SRIOV device. For fallback, agreed on adding a blacklist for mlx5-core I saw that on this system as well: eth0 is driver/module: module -> ../../../../module/hv_netvsc rename3 : module -> ../../../../module/mlx5_core We can add an issue and add that blacklist driver in a followup. Much thanks James for the branch and Ryan for chiming in on the review here. I think we all agree this is +1. My tests confirmed 90 second boot timeout on cloud-init-local (bionic Azure) on DS2v2 instance type, after upgrade to cloud-init (and reboot) network config regen'd with driver :hv_netvsc allocated the right ip addr to eth0, avoids rename naming collision and boots without painful cloud-init-local http://paste.ubuntu.com/p/2kPKbvGc4y/ http://paste.ubuntu.com/p/G5v8Hg9JhY/ http://paste.ubuntu.com/p/3tmx5RCG65/

…

On Mon, Aug 24, 2020 at 4:12 PM Ryan Harper ***@***.***> wrote: ***@***.**** commented on this pull request. ------------------------------ In cloudinit/sources/DataSourceAzure.py <#539 (comment)>: > @@ -1387,9 +1388,16 @@ def parse_network_config(imds_metadata): ip=privateIp, prefix=netPrefix)) if dev_config: mac = ':'.join(re.findall(r'..', intf['macAddress'])) - dev_config.update( - {'match': {'macaddress': mac.lower()}, - 'set-name': nicname}) + dev_config.update({ + 'match': {'macaddress': mac.lower()}, + 'set-name': nicname + }) + # With netvsc, we can get two interfaces that + # share the same MAC, so we need to make sure Thanks. I think this is the right fix; I think we overlooked preventing network-v2 config from matching non-hyperv nics once we started crawling IMDS; It's possible that this was not noticed as there is a race between the kernel completes the SRIOV bond and when cloud-init starts to generate networking. Let's confirm that IMDS does not include an SRIOV device (I don't think it will since it contains a duplicate mac of one of the hyperv nics). For fallback, we need to update the blacklist to include mlx5-core (newer hardware). This is only important for Xenial (and non-netplan rendered targets) I believe those paths will ignore the mlx devices, but we should also ensure that the driver value is emitted in the udev rule ( — You are receiving this because you were assigned. Reply to this email directly, view it on GitHub <#539 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/ADLZJRRFERYMOGK3MTEV2L3SCLQTPANCNFSM4QHVY6NQ> .

blackboxsw

+1 confirmed behavior fix on instances with enhanced networking. validated no regression on clean and dirty reboots

TheRealFalcon added the wip Work in progress, do not land label Aug 21, 2020

TheRealFalcon force-pushed the same-mac-fix branch from 576ba03 to 971dfc7 Compare August 24, 2020 14:36

TheRealFalcon removed the wip Work in progress, do not land label Aug 24, 2020

TheRealFalcon force-pushed the same-mac-fix branch from 971dfc7 to bc14d3a Compare August 24, 2020 14:59

blackboxsw self-assigned this Aug 24, 2020

mitechie approved these changes Aug 24, 2020

View reviewed changes

raharper reviewed Aug 24, 2020

View reviewed changes

Merge branch 'master' into same-mac-fix

6a19e8d

blackboxsw approved these changes Aug 25, 2020

View reviewed changes

blackboxsw merged commit 4068137 into canonical:master Aug 25, 2020

TheRealFalcon deleted the same-mac-fix branch August 25, 2020 13:23

johnsonshi mentioned this pull request Aug 26, 2020

Azure parse_network_config uses fallback cfg when generate IMDS network cfg fails #549

Merged

blackboxsw mentioned this pull request Sep 9, 2020

sru: manual verification on azure of gh-529, 539, 494 cloud-init/ubuntu-sru#159

Merged

ubuntu-server-builder mentioned this pull request May 12, 2023

Release 20.3 #3774

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Azure: Add netplan driver filter when using hv_netvsc driver #539

Azure: Add netplan driver filter when using hv_netvsc driver #539

TheRealFalcon commented Aug 21, 2020 •

edited

Loading

TheRealFalcon commented Aug 24, 2020 •

edited

Loading

raharper Aug 24, 2020

blackboxsw Aug 24, 2020 •

edited

Loading

raharper Aug 24, 2020

blackboxsw commented Aug 25, 2020 via email

blackboxsw left a comment

Azure: Add netplan driver filter when using hv_netvsc driver #539

Azure: Add netplan driver filter when using hv_netvsc driver #539

Conversation

TheRealFalcon commented Aug 21, 2020 • edited Loading

TheRealFalcon commented Aug 24, 2020 • edited Loading

raharper Aug 24, 2020

Choose a reason for hiding this comment

blackboxsw Aug 24, 2020 • edited Loading

Choose a reason for hiding this comment

raharper Aug 24, 2020

Choose a reason for hiding this comment

blackboxsw commented Aug 25, 2020 via email

blackboxsw left a comment

Choose a reason for hiding this comment

TheRealFalcon commented Aug 21, 2020 •

edited

Loading

TheRealFalcon commented Aug 24, 2020 •

edited

Loading

blackboxsw Aug 24, 2020 •

edited

Loading