Node is unreachable after node is launched by Nodepool

Thank you for reporting bug!

Describe the bug

This issue only happen in Packet public cloud. Packet instance is launched by OpenLab Nodepool, and show it as available node in pool, then the instance may be unreachable after a period of time, if OpenLab Zuul dispatch a job to the instance, will cause job RETRY_LIMIT failing.

We know Nodepool will check whether node is available by SSH host checking after launching it, if can't access, Nodepool will delete the instance, try to launch new one. So we guess Nodepool checking is OK, but instance can be accessed after a period of time.

Zuul job log in OpenLab

2019-03-20 09:14:10.431694 | ubuntu-xenial | Triggered by: https://review.openstack.org/ patchset
2019-03-20 09:14:10.431811 | ubuntu-xenial | Pipeline: periodic
2019-03-20 09:14:10.431934 | ubuntu-xenial | Timeout set to 170 minutes with 10 minutes reserved for cleanup.
2019-03-20 09:14:10.431995 | ubuntu-xenial | Available disk space on this host:
2019-03-20 09:14:10.433847 | ubuntu-xenial |     Filesystem      Size  Used Avail Use% Mounted on
2019-03-20 09:14:10.433936 | ubuntu-xenial |     udev            3.9G     0  3.9G   0% /dev
2019-03-20 09:14:10.434030 | ubuntu-xenial |     tmpfs           799M  640K  798M   1% /run
2019-03-20 09:14:10.434130 | ubuntu-xenial |     /dev/vda1        75G  3.5G   69G   5% /
2019-03-20 09:14:10.434201 | ubuntu-xenial |     tmpfs           3.9G     0  3.9G   0% /dev/shm
2019-03-20 09:14:10.434276 | ubuntu-xenial |     tmpfs           5.0M     0  5.0M   0% /run/lock
2019-03-20 09:14:10.434360 | ubuntu-xenial |     tmpfs           3.9G     0  3.9G   0% /sys/fs/cgroup
2019-03-20 09:14:10.434439 | ubuntu-xenial |     /dev/sr0        446K  446K     0 100% /mnt/config
2019-03-20 09:14:10.434504 | ubuntu-xenial |     tmpfs           799M     0  799M   0% /run/user/1000
2019-03-20 09:14:10.878271 | ubuntu-xenial | DEPRECATION: Python 2.7 will reach the end of its life on January 1st, 2020. Please upgrade your Python as Python 2.7 won't be maintained after that date. A future version of pip will drop support for Python 2.7.
2019-03-20 09:14:10.991471 | ubuntu-xenial | Requirement already satisfied: virtualenv in /usr/local/lib/python2.7/dist-packages (16.4.3)
2019-03-20 09:14:11.284084 | ubuntu-xenial | New python executable in /tmp/ansible/bin/python2
2019-03-20 09:14:11.288916 | ubuntu-xenial | Also creating executable in /tmp/ansible/bin/python
2019-03-20 09:14:12.101158 | ubuntu-xenial | Installing setuptools, pip, wheel...
2019-03-20 09:14:14.560148 | ubuntu-xenial | done.
2019-03-20 09:14:14.828265 | ubuntu-xenial | DEPRECATION: Python 2.7 will reach the end of its life on January 1st, 2020. Please upgrade your Python as Python 2.7 won't be maintained after that date. A future version of pip will drop support for Python 2.7.
2019-03-20 09:18:50.974315 | [Zuul] Log Stream did not terminate
2019-03-20 09:19:20.975067 | [Zuul] Log Stream did not terminate
2019-03-20 09:19:20.975523 | ubuntu-xenial | ERROR
2019-03-20 09:19:20.975786 | ubuntu-xenial | {
2019-03-20 09:19:20.975895 | ubuntu-xenial |   "msg": "SSH Error: data could not be sent to remote host \"147.75.38.150\". Make sure this host can be reached over ssh",
2019-03-20 09:19:20.976027 | ubuntu-xenial |   "unreachable": true
2019-03-20 09:19:20.976119 | ubuntu-xenial | }
2019-03-20 09:19:20.978011 | 
2019-03-20 09:19:20.978108 | PLAY RECAP
2019-03-20 09:19:20.978249 | ubuntu-xenial | ok: 5 changed: 5 unreachable: 1 failed: 0
2019-03-20 09:19:20.978367 | 
2019-03-20 09:19:21.083734 | RUN END RESULT_UNREACHABLE: [trusted : github.com/theopenlab/openlab-zuul-jobs/playbooks/ansible-functional-devstack/run.yaml@master]
root@donotdel-openlab-zuul:/tmp/tmpf1lsxx87/0b8d360b509743e1b4512f55093aaf22# less /tmp/tmpf1lsxx87/b3750b14f0bd491a9a42399b9f921d6e/work/logs/zuul-info/inventory.yaml

Instance 147.75.38.151 is unreachable, but other nodes are OK

stack@ubuntu1604 ~ $ openstack --os-cloud openlab-packet server list
+--------------------------------------+--------------------------------------------+--------+---------------------------------------------+----------------------------------+-------------+
| ID                                   | Name                                       | Status | Networks                                    | Image                            | Flavor      |
+--------------------------------------+--------------------------------------------+--------+---------------------------------------------+----------------------------------+-------------+
| f696454f-f5aa-495b-a379-0e4df5cbf53c | ubuntu-xenial-ut-packet-openlab-0000004110 | ACTIVE | openlabzuul-net=192.168.1.15, 147.75.38.162 | openlab-ubuntu-xenial-1552901589 | m1.small    |
| 5b127da2-0e17-4e81-9eb7-e4a9bfd14eb6 | ubuntu-xenial-packet-openlab-0000004109    | ACTIVE | openlabzuul-net=192.168.1.19, 147.75.38.155 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 1d1d8044-b6f7-442f-832c-d5b6bd7906eb | ubuntu-xenial-packet-openlab-0000004097    | ACTIVE | openlabzuul-net=192.168.1.21, 147.75.38.142 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 6069169d-2952-4063-b6a0-ec17db1c6bd0 | ubuntu-xenial-packet-openlab-0000004063    | ACTIVE | openlabzuul-net=192.168.1.8, 147.75.38.136  | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 9c87d1eb-8d74-40c2-b572-196583b7004b | ubuntu-xenial-packet-openlab-0000004062    | ACTIVE | openlabzuul-net=192.168.1.18, 147.75.38.137 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 0f3818d8-96e5-4ac4-a1fe-e5f89cd0d9ce | ubuntu-xenial-packet-openlab-0000004050    | ACTIVE | openlabzuul-net=192.168.1.14, 147.75.38.145 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 7168c106-4497-4f1b-b010-de1ea09d2963 | ubuntu-xenial-packet-openlab-0000004049    | ACTIVE | openlabzuul-net=192.168.1.3, 147.75.38.135  | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 3ecc2854-ff52-4f65-ac2c-fd11f8cd9160 | ubuntu-xenial-packet-openlab-0000004048    | ACTIVE | openlabzuul-net=192.168.1.12, 147.75.38.151 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| e4e16050-8e93-412d-a537-4ef3d9aa0602 | ubuntu-xenial-packet-openlab-0000004047    | ACTIVE | openlabzuul-net=192.168.1.11, 147.75.38.140 | openlab-ubuntu-xenial-1552901589 | zuul-flavor |
| 3d3065a8-2164-4d10-bc16-dac7f7b91af5 | ubuntu-trusty-packet-openlab-0000004024    | ACTIVE | openlabzuul-net=192.168.1.6, 147.75.38.146  | openlab-ubuntu-trusty-1552901339 | zuul-flavor |
+--------------------------------------+--------------------------------------------+--------+---------------------------------------------+----------------------------------+-------------+

openstack console log show

stack@ubuntu1604 ~ $ openstack --os-cloud openlab-packet console log show ubuntu-xenial-packet-openlab-0000005026 
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.4.0-143-generic (buildd@lgw01-amd64-041) (gcc version 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.10) ) #169-Ubuntu SMP Thu Feb 7 07:56:38 UTC 2019 (Ubuntu 4.4.0-143.169-generic 4.4.170)
[    0.000000] Command line: BOOT_IMAGE=/boot/vmlinuz-4.4.0-143-generic root=LABEL=cloudimg-rootfs ro console=tty1 console=ttyS0
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Centaur CentaurHauls
[    0.000000] x86/fpu: xstate_offset[2]:  576, xstate_sizes[2]:  256
[    0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'
[    0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'
[    0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x00000000bffdefff] usable
[    0.000000] BIOS-e820: [mem 0x00000000bffdf000-0x00000000bfffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000100000000-0x000000023fffffff] usable
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] SMBIOS 2.8 present.
[    0.000000] Hypervisor detected: KVM
[    0.000000] e820: last_pfn = 0x240000 max_arch_pfn = 0x400000000
[    0.000000] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- WT  
[    0.000000] e820: last_pfn = 0xbffdf max_arch_pfn = 0x400000000
[    0.000000] found SMP MP-table at [mem 0x000f6590-0x000f659f] mapped at [ffff8800000f6590]
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] Using GB pages for direct mapping
[    0.000000] RAMDISK: [mem 0x33464000-0x35a29fff]
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F6540 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x00000000BFFE14CE 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x00000000BFFE0814 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x00000000BFFDFC40 000BD4 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x00000000BFFDFC00 000040
[    0.000000] ACPI: SSDT 0x00000000BFFE0888 000B96 (v01 BOCHS  BXPCSSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: APIC 0x00000000BFFE141E 0000B0 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] No NUMA configuration found
[    0.000000] Faking a node at [mem 0x0000000000000000-0x000000023fffffff]
[    0.000000] NODE_DATA(0) allocated [mem 0x23fff9000-0x23fffdfff]
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 2:3fff1001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 1574054963 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x00000000ffffffff]
[    0.000000]   Normal   [mem 0x0000000100000000-0x000000023fffffff]
[    0.000000]   Device   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x00000000bffdefff]
[    0.000000]   node   0: [mem 0x0000000100000000-0x000000023fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000023fffffff]
[    0.000000] ACPI: PM-Timer IO Port: 0x608
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] smpboot: Allowing 8 CPUs, 0 hotplug CPUs
[    0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]
[    0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]
[    0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[    0.000000] PM: Registered nosave memory: [mem 0xbffdf000-0xbfffffff]
[    0.000000] PM: Registered nosave memory: [mem 0xc0000000-0xfeffbfff]
[    0.000000] PM: Registered nosave memory: [mem 0xfeffc000-0xfeffffff]
[    0.000000] PM: Registered nosave memory: [mem 0xff000000-0xfffbffff]
[    0.000000] PM: Registered nosave memory: [mem 0xfffc0000-0xffffffff]
[    0.000000] e820: [mem 0xc0000000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
[    0.000000] setup_percpu: NR_CPUS:512 nr_cpumask_bits:512 nr_cpu_ids:8 nr_node_ids:1
[    0.000000] PERCPU: Embedded 34 pages/cpu @ffff88023fc00000 s99480 r8192 d31592 u262144
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr 23fc10200
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.  Total pages: 2064231
[    0.000000] Policy zone: Normal
[    0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-4.4.0-143-generic root=LABEL=cloudimg-rootfs ro console=tty1 console=ttyS0
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Memory: 8132256K/8388084K available (8608K kernel code, 1332K rwdata, 4008K rodata, 1484K init, 1316K bss, 255828K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
[    0.000000] Kernel/User page tables isolation: enabled
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 64.
[    0.000000]  RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=8.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=8
[    0.000000] NR_IRQS:33024 nr_irqs:488 16
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [tty1] enabled
[    0.000000] console [ttyS0] enabled
[    0.000000] tsc: Detected 2199.994 MHz processor
[    1.098633] Calibrating delay loop (skipped) preset value.. 4399.98 BogoMIPS (lpj=8799976)
[    1.099953] pid_max: default: 32768 minimum: 301
[    1.100731] ACPI: Core revision 20150930
[    1.102686] ACPI: 2 ACPI AML tables successfully acquired and loaded
[    1.103788] Security Framework initialized
[    1.104462] Yama: becoming mindful.
[    1.105127] AppArmor: AppArmor initialized
[    1.115492] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes)
[    1.156733] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    1.170972] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes)
[    1.172167] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes)
[    1.182819] Initializing cgroup subsys io
[    1.183449] Initializing cgroup subsys memory
[    1.184147] Initializing cgroup subsys devices
[    1.184895] Initializing cgroup subsys freezer
[    1.185615] Initializing cgroup subsys net_cls
[    1.186338] Initializing cgroup subsys perf_event
[    1.187128] Initializing cgroup subsys net_prio
[    1.187872] Initializing cgroup subsys hugetlb
[    1.188584] Initializing cgroup subsys pids
[    1.190204] mce: CPU supports 10 MCE banks
[    1.190900] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    1.191685] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    1.192635] Spectre V2 : Mitigation: Full generic retpoline
[    1.193531] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    1.194799] Speculative Store Bypass: Vulnerable
[    1.198938] Freeing SMP alternatives memory: 32K
[    1.206604] ftrace: allocating 32278 entries in 127 pages
[    1.279644] smpboot: APIC(0) Converting physical 0 to logical package 0
[    1.280729] smpboot: APIC(1) Converting physical 1 to logical package 1
[    1.281847] smpboot: APIC(2) Converting physical 2 to logical package 2
[    1.282888] smpboot: APIC(3) Converting physical 3 to logical package 3
[    1.283969] smpboot: APIC(4) Converting physical 4 to logical package 4
[    1.285004] smpboot: APIC(5) Converting physical 5 to logical package 5
[    1.286159] smpboot: APIC(6) Converting physical 6 to logical package 6
[    1.287273] smpboot: APIC(7) Converting physical 7 to logical package 7
[    1.288337] smpboot: Max logical packages: 8
[    1.289262] x2apic enabled
[    1.290134] Switched APIC routing to physical x2apic.
[    1.292267] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    1.293506] smpboot: CPU0: Intel Core Processor (Broadwell) (family: 0x6, model: 0x3d, stepping: 0x2)
[    1.295352] Performance Events: unsupported p6 CPU model 61 no PMU driver, software events only.
[    1.298604] x86: Booting SMP configuration:
[    1.299442] .... node  #0, CPUs:      #1
[    1.300409] kvm-clock: cpu 1, msr 2:3fff1041, secondary cpu clock
[    1.323193] KVM setup async PF for cpu 1
[    1.323678]  #2
[    1.323678] kvm-clock: cpu 2, msr 2:3fff1081, secondary cpu clock
[    1.326687] kvm-stealtime: cpu 1, msr 23fc50200
[    1.344900] KVM setup async PF for cpu 2
[    1.346223] kvm-stealtime: cpu 2, msr 23fc90200
[    1.353687]  #3
[    1.354186] kvm-clock: cpu 3, msr 2:3fff10c1, secondary cpu clock
[    1.376844] KVM setup async PF for cpu 3
[    1.377338]  #4
[    1.377338] kvm-clock: cpu 4, msr 2:3fff1101, secondary cpu clock
[    1.380449] kvm-stealtime: cpu 3, msr 23fcd0200
[    1.398607] KVM setup async PF for cpu 4
[    1.399078]  #5
[    1.399079] kvm-clock: cpu 5, msr 2:3fff1141, secondary cpu clock
[    1.402106] kvm-stealtime: cpu 4, msr 23fd10200
[    1.420239] KVM setup async PF for cpu 5
[    1.420761]  #6
[    1.420761] kvm-clock: cpu 6, msr 2:3fff1181, secondary cpu clock
[    1.423234] kvm-stealtime: cpu 5, msr 23fd50200
[    1.442005] KVM setup async PF for cpu 6
[    1.442467]  #7
[    1.442467] kvm-clock: cpu 7, msr 2:3fff11c1, secondary cpu clock
[    1.445136] kvm-stealtime: cpu 6, msr 23fd90200
[    1.463639] x86: Booted up 1 node, 8 CPUs
[    1.463648] KVM setup async PF for cpu 7
[    1.463658] kvm-stealtime: cpu 7, msr 23fdd0200
[    1.465751] smpboot: Total of 8 processors activated (35199.90 BogoMIPS)
[    1.468433] devtmpfs: initialized
[    1.471633] evm: security.selinux
[    1.472227] evm: security.SMACK64
[    1.472842] evm: security.SMACK64EXEC
[    1.473522] evm: security.SMACK64TRANSMUTE
[    1.474233] evm: security.SMACK64MMAP
[    1.474823] evm: security.ima
[    1.475298] evm: security.capability
[    1.476260] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    1.477941] futex hash table entries: 2048 (order: 5, 131072 bytes)
[    1.479300] pinctrl core: initialized pinctrl subsystem
[    1.480436] RTC time:  4:14:41, date: 03/20/19
[    1.482588] NET: Registered protocol family 16
[    1.492359] cpuidle: using governor ladder
[    1.504500] cpuidle: using governor menu
[    1.505220] PCCT header not found.
[    1.506096] ACPI: bus type PCI registered
[    1.506804] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
[    1.508098] PCI: Using configuration type 1 for base access
[    1.531270] ACPI: Added _OSI(Module Device)
[    1.532028] ACPI: Added _OSI(Processor Device)
[    1.532806] ACPI: Added _OSI(3.0 _SCP Extensions)
[    1.533636] ACPI: Added _OSI(Processor Aggregator Device)
[    1.536153] ACPI: Interpreter enabled
[    1.536873] ACPI: (supports S0 S3 S4 S5)
[    1.537612] ACPI: Using IOAPIC for interrupt routing
[    1.538531] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    1.543231] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    1.544305] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[    1.545563] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    1.546710] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    1.549055] acpiphp: Slot [3] registered
[    1.549862] acpiphp: Slot [4] registered
[    1.550560] acpiphp: Slot [5] registered
[    1.551245] acpiphp: Slot [6] registered
[    1.551990] acpiphp: Slot [7] registered
[    1.552766] acpiphp: Slot [8] registered
[    1.553554] acpiphp: Slot [9] registered
[    1.554265] acpiphp: Slot [10] registered
[    1.554947] acpiphp: Slot [11] registered
[    1.555708] acpiphp: Slot [12] registered
[    1.556386] acpiphp: Slot [13] registered
[    1.557131] acpiphp: Slot [14] registered
[    1.557925] acpiphp: Slot [15] registered
[    1.558628] acpiphp: Slot [16] registered
[    1.559415] acpiphp: Slot [17] registered
[    1.560122] acpiphp: Slot [18] registered
[    1.560839] acpiphp: Slot [19] registered
[    1.561543] acpiphp: Slot [20] registered
[    1.562270] acpiphp: Slot [21] registered
[    1.563003] acpiphp: Slot [22] registered
[    1.563719] acpiphp: Slot [23] registered
[    1.564419] acpiphp: Slot [24] registered
[    1.565159] acpiphp: Slot [25] registered
[    1.565880] acpiphp: Slot [26] registered
[    1.566552] acpiphp: Slot [27] registered
[    1.567289] acpiphp: Slot [28] registered
[    1.568016] acpiphp: Slot [29] registered
[    1.568811] acpiphp: Slot [30] registered
[    1.569561] acpiphp: Slot [31] registered
[    1.570335] PCI host bridge to bus 0000:00
[    1.571029] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    1.572192] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    1.573387] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    1.574783] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xfebfffff window]
[    1.575975] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.584863] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
[    1.586072] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
[    1.587121] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
[    1.588335] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
[    1.596800] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
[    1.598100] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
[    1.674220] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    1.675718] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    1.677165] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    1.679293] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    1.680536] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    1.682716] ACPI: Enabled 16 GPEs in block 00 to 0F
[    1.684830] vgaarb: setting as boot device: PCI:0000:00:02.0
[    1.686455] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[    1.688836] vgaarb: loaded
[    1.689658] vgaarb: bridge control possible 0000:00:02.0
[    1.692357] SCSI subsystem initialized
[    1.694207] ACPI: bus type USB registered
[    1.695542] usbcore: registered new interface driver usbfs
[    1.697166] usbcore: registered new interface driver hub
[    1.698867] usbcore: registered new device driver usb
[    1.701041] PCI: Using ACPI for IRQ routing
[    1.703025] NetLabel: Initializing
[    1.703965] NetLabel:  domain hash size = 128
[    1.705219] NetLabel:  protocols = UNLABELED CIPSOv4
[    1.706615] NetLabel:  unlabeled traffic allowed by default
[    1.708524] amd_nb: Cannot enumerate AMD northbridges
[    1.710197] clocksource: Switched to clocksource kvm-clock
[    1.730146] AppArmor: AppArmor Filesystem Enabled
[    1.731548] pnp: PnP ACPI init
[    1.733140] pnp: PnP ACPI: found 6 devices
[    1.743648] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    1.745813] NET: Registered protocol family 2
[    1.747399] TCP established hash table entries: 65536 (order: 7, 524288 bytes)
[    1.749736] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[    1.752353] TCP: Hash tables configured (established 65536 bind 65536)
[    1.753765] UDP hash table entries: 4096 (order: 5, 131072 bytes)
[    1.755124] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes)
[    1.756588] NET: Registered protocol family 1
[    1.757536] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    1.758731] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    1.759872] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    1.793970] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[    1.825030] Unpacking initramfs...
[    2.615030] Freeing initrd memory: 38680K
[    2.615852] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[    2.617536] software IO TLB: mapped [mem 0xbbfdf000-0xbffdf000] (64MB)
[    2.630090] Scanning for low memory corruption every 60 seconds
[    2.632076] audit: initializing netlink subsys (disabled)
[    2.633678] audit: type=2000 audit(1553055282.815:1): initialized
[    2.636060] Initialise system trusted keyring
[    2.637816] HugeTLB registered 1 GB page size, pre-allocated 0 pages
[    2.639648] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    2.644102] zbud: loaded
[    2.645829] VFS: Disk quotas dquot_6.6.0
[    2.646976] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    2.649294] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    2.651499] fuse init (API version 7.23)
[    2.653531] Key type big_key registered
[    2.654628] Allocating IMA MOK and blacklist keyrings.
[    2.657813] Key type asymmetric registered
[    2.658860] Asymmetric key parser 'x509' registered
[    2.660105] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    2.662067] io scheduler noop registered
[    2.663056] io scheduler deadline registered (default)
[    2.664356] io scheduler cfq registered
[    2.665493] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    2.666898] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    2.668552] efifb: probing for efifb
[    2.669460] efifb: framebuffer at 0xfc000000, mapped to 0xffffc90001000000, using 1408k, total 1408k
[    2.671607] efifb: mode is 800x600x24, linelength=2400, pages=1
[    2.672934] efifb: scrolling: redraw
[    2.673760] efifb: Truecolor: size=0:8:8:8, shift=0:16:8:0
[    2.678879] Console: switching to colour frame buffer device 100x37
[    2.683008] fb0: EFI VGA frame buffer device
[    2.684147] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    2.685803] ACPI: Power Button [PWRF]
[    2.687174] GHES: HEST is not enabled!
[    2.722088] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 10
[    2.723262] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
[    2.753903] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[    2.798023] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[    2.799578] virtio-pci 0000:00:05.0: virtio_pci: leaving for legacy driver
[    2.802999] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled
[    2.831033] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    2.858718] 00:05: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    2.862549] Linux agpgart interface v0.103
[    2.877496] loop: module loaded
[    2.881246]  vda: vda1
[    2.884211] scsi host0: ata_piix
[    2.885990] scsi host1: ata_piix
[    2.887477] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc0a0 irq 14
[    2.889416] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0a8 irq 15
[    2.891515] libphy: Fixed MDIO Bus: probed
[    2.893209] tun: Universal TUN/TAP device driver, 1.6
[    2.896506] tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
[    2.903939] PPP generic driver version 2.4.2
[    2.906978] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    2.910072] ehci-pci: EHCI PCI platform driver
[    2.912563] ehci-platform: EHCI generic platform driver
[    2.915392] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    2.918315] ohci-pci: OHCI PCI platform driver
[    2.920816] ohci-platform: OHCI generic platform driver
[    2.923553] uhci_hcd: USB Universal Host Controller Interface driver
[    2.963428] uhci_hcd 0000:00:01.2: UHCI Host Controller
[    2.965720] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[    2.968418] uhci_hcd 0000:00:01.2: detected 2 ports
[    2.970420] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c040
[    2.972293] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[    2.974638] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.976637] usb usb1: Product: UHCI Host Controller
[    2.978313] usb usb1: Manufacturer: Linux 4.4.0-143-generic uhci_hcd
[    2.980184] usb usb1: SerialNumber: 0000:00:01.2
[    2.982005] hub 1-0:1.0: USB hub found
[    2.983473] hub 1-0:1.0: 2 ports detected
[    2.985201] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    2.988329] serio: i8042 KBD port at 0x60,0x64 irq 1
[    2.990039] serio: i8042 AUX port at 0x60,0x64 irq 12
[    3.002175] mousedev: PS/2 mouse device common for all mice
[    3.004206] rtc_cmos 00:00: RTC can wake from S4
[    3.006385] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    3.008709] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[    3.010874] rtc_cmos 00:00: alarms up to one day, 114 bytes nvram
[    3.012732] i2c /dev entries driver
[    3.014292] device-mapper: uevent: version 1.0.3
[    3.016492] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com
[    3.018833] ledtrig-cpu: registered to indicate activity on CPUs
[    3.021407] NET: Registered protocol family 10
[    3.023583] NET: Registered protocol family 17
[    3.025219] Key type dns_resolver registered
[    3.027428] registered taskstats version 1
[    3.029011] Loading compiled-in X.509 certificates
[    3.031581] Loaded X.509 cert 'Build time autogenerated kernel key: d03773f65dd2b75b701d4dd50cb1e8d0c07b3b6e'
[    3.035093] zswap: loaded using pool lzo/zbud
[    3.040013] Key type trusted registered
[    3.047029] ata1.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[    3.047190] Key type encrypted registered
[    3.047196] AppArmor: AppArmor sha1 policy hashing enabled
[    3.047206] ima: No TPM chip found, activating TPM-bypass!
[    3.047226] ima: Allocated hash algorithm: sha1
[    3.047256] evm: HMAC attrs: 0x1
[    3.047800]   Magic number: 11:74:212
[    3.048821] rtc_cmos 00:00: setting system clock to 2019-03-20 04:14:43 UTC (1553055283)
[    3.049038] BIOS EDD facility v0.16 2004-Jun-25, 0 devices found
[    3.049039] EDD information not available.
[    3.063881] ata1.00: configured for MWDMA2
[    3.066329] scsi 0:0:0:0: CD-ROM            QEMU     QEMU DVD-ROM     2.5+ PQ: 0 ANSI: 5
[    3.069910] sr 0:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[    3.071950] cdrom: Uniform CD-ROM driver Revision: 3.20
[    3.074014] sr 0:0:0:0: Attached scsi generic sg0 type 5
[    3.078054] Freeing unused kernel memory: 1484K
[    3.098237] Write protecting the kernel read-only data: 14336k
[    3.101932] Freeing unused kernel memory: 1620K
[    3.104025] Freeing unused kernel memory: 88K
Loading, please wait...
starting version 229
[    3.142793] random: systemd-udevd: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.143797] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.143827] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.153268] random: systemd-udevd: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.155998] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.156055] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.156712] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.156782] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.156855] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.156938] random: udevadm: uninitialized urandom read (16 bytes read, 3 bits of entropy available)
[    3.220404] [drm] Initialized drm 1.1.0 20060810
[    3.231163] FDC 0 is a S82078B
[    3.236098] virtio_net virtio0 ens3: renamed from eth0
[    3.255144] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input4
[    3.260937] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3
[    3.261058] AVX2 version of gcm_enc/dec engaged.
[    3.261058] AES CTR mode by8 optimization enabled
[    3.283139] fb: switching to cirrusdrmfb from EFI VGA
[    3.285704] Console: switching to colour dummy device 80x25
[    3.287258] [TTM] Zone  kernel: Available graphics memory: 4087080 kiB
[    3.288486] [TTM] Zone   dma32: Available graphics memory: 2097152 kiB
[    3.289738] [TTM] Initializing pool allocator
[    3.290550] [TTM] Initializing DMA pool allocator
[    3.291756] [drm] fb mappable at 0xFC000000
[    3.292513] [drm] vram aper at 0xFC000000
[    3.293249] [drm] size 33554432
[    3.293840] [drm] fb depth is 24
[    3.294439] [drm]    pitch is 3072
[    3.295051] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[    3.296356] fbcon: cirrusdrmfb (fb0) is primary device
[    3.299008] Console: switching to colour frame buffer device 128x48
[    3.317442] cirrus 0000:00:02.0: fb0: cirrusdrmfb frame buffer device
[    3.334276] [drm] Initialized cirrus 1.0.0 20110418 for 0000:00:02.0 on minor 0
[    3.459218] usb 1-1: New USB device found, idVendor=0627, idProduct=0001
[    3.460608] usb 1-1: New USB device strings: Mfr=1, Product=3, SerialNumber=5
[    3.462228] usb 1-1: Product: QEMU USB Tablet
[    3.463135] usb 1-1: Manufacturer: QEMU
[    3.464263] usb 1-1: SerialNumber: 42
[    3.476279] hidraw: raw HID events driver (C) Jiri Kosina
[    3.484071] usbcore: registered new interface driver usbhid
[    3.485360] usbhid: USB HID core driver
[    3.489094] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input5
[    3.492038] hid-generic 0003:0627:0001.0001: input,hidraw0: USB HID v0.01 Pointer [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[    3.626291] tsc: Refined TSC clocksource calibration: 2200.001 MHz
[    3.627682] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1fb633bd18b, max_idle_ns: 440795253614 ns
Begin: Loading essential drivers ... [    3.691701] md: linear personality registered for level -1
[    3.697252] md: multipath personality registered for level -4
[    3.703008] md: raid0 personality registered for level 0
[    3.709365] md: raid1 personality registered for level 1
[    3.786275] raid6: sse2x1   gen()  7212 MB/s
[    3.854242] raid6: sse2x1   xor()  5509 MB/s
[    3.922223] raid6: sse2x2   gen()  9559 MB/s
[    3.990236] raid6: sse2x2   xor()  6265 MB/s
[    4.058236] raid6: sse2x4   gen() 10750 MB/s
[    4.126254] raid6: sse2x4   xor()  6675 MB/s
[    4.194233] raid6: avx2x1   gen() 13541 MB/s
[    4.262208] raid6: avx2x2   gen() 15801 MB/s
[    4.330224] raid6: avx2x4   gen() 18033 MB/s
[    4.332133] raid6: using algorithm avx2x4 gen() 18033 MB/s
[    4.334145] raid6: using avx2x2 recovery algorithm
[    4.337804] xor: automatically using best checksumming function:
[    4.378242]    avx       : 20140.000 MB/sec
[    4.381697] async_tx: api initialized (async)
[    4.391659] md: raid6 personality registered for level 6
[    4.393752] md: raid5 personality registered for level 5
[    4.395697] md: raid4 personality registered for level 4
[    4.407231] md: raid10 personality registered for level 10
done.
Begin: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... [    4.457580] Btrfs loaded
Scanning for Btrfs filesystems
done.
Warning: fsck not present, so skipping root file system
[    4.516097] EXT4-fs (vda1): mounted filesystem with ordered data mode. Opts: (null)
done.
Begin: Running /scripts/local-bottom ... done.
Begin: Running /scripts/init-bottom ... done.
[    4.727847] systemd[1]: systemd 229 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ -LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN)
[    4.735572] systemd[1]: Detected virtualization kvm.
[    4.738379] systemd[1]: Detected architecture x86-64.

Welcome to [1mUbuntu 16.04.6 LTS[0m!

[    4.744010] systemd[1]: Set hostname to <ubuntu>.
[    4.749152] systemd[1]: Initializing machine ID from KVM UUID.
[    4.752112] systemd[1]: Installed transient /etc/machine-id file.
[    4.929912] systemd[1]: basic.target: Found ordering cycle on basic.target/start
[    4.932255] systemd[1]: basic.target: Found dependency on sockets.target/start
[    4.934509] systemd[1]: basic.target: Found dependency on apport-forward.socket/start
[    4.936806] systemd[1]: basic.target: Found dependency on sysinit.target/start
[    4.939016] systemd[1]: basic.target: Found dependency on cloud-init.service/start
[    4.941196] systemd[1]: basic.target: Found dependency on networking.service/start
[    4.943373] systemd[1]: basic.target: Found dependency on network-pre.target/start
[    4.945542] systemd[1]: basic.target: Found dependency on initialize-urandom.service/start
[    4.947768] systemd[1]: basic.target: Found dependency on basic.target/start
[    4.949821] systemd[1]: basic.target: Breaking ordering cycle by deleting job sockets.target/start
[    4.952153] systemd[1]: sockets.target: Job sockets.target/start deleted to break ordering cycle starting with basic.target/start
[[0;1;31m SKIP [0m] Ordering cycle found, skipping Sockets
[    4.957546] systemd[1]: basic.target: Found ordering cycle on basic.target/start
[    4.959668] systemd[1]: basic.target: Found dependency on paths.target/start
[    4.961723] systemd[1]: basic.target: Found dependency on acpid.path/start
[    4.963689] systemd[1]: basic.target: Found dependency on sysinit.target/start
[    4.965680] systemd[1]: basic.target: Found dependency on cloud-init.service/start
[    4.967685] systemd[1]: basic.target: Found dependency on networking.service/start
[    4.969713] systemd[1]: basic.target: Found dependency on network-pre.target/start
[    4.971696] systemd[1]: basic.target: Found dependency on initialize-urandom.service/start
[    4.973849] systemd[1]: basic.target: Found dependency on basic.target/start
[    4.975763] systemd[1]: basic.target: Breaking ordering cycle by deleting job paths.target/start
[    4.977931] systemd[1]: paths.target: Job paths.target/start deleted to break ordering cycle starting with basic.target/start
[[0;1;31m SKIP [0m] Ordering cycle found, skipping Paths
[    4.981931] systemd[1]: initialize-urandom.service: Found ordering cycle on initialize-urandom.service/start
[    4.984305] systemd[1]: initialize-urandom.service: Found dependency on sysinit.target/start
[    4.986541] systemd[1]: initialize-urandom.service: Found dependency on cloud-init.service/start
[    4.988799] systemd[1]: initialize-urandom.service: Found dependency on networking.service/start
[    4.991151] systemd[1]: initialize-urandom.service: Found dependency on network-pre.target/start
[    4.993379] systemd[1]: initialize-urandom.service: Found dependency on initialize-urandom.service/start
[    4.995898] systemd[1]: initialize-urandom.service: Breaking ordering cycle by deleting job cloud-init.service/start
[    4.998544] systemd[1]: cloud-init.service: Job cloud-init.service/start deleted to break ordering cycle starting with initialize-urandom.service/start
[[0;1;31m SKIP [0m] Ordering cycle found, skipping Init...t job (metadata service crawler)
[    5.005588] systemd[1]: Listening on Journal Audit Socket.
[[0;32m  OK  [0m] Listening on Journal Audit Socket.
[    5.008739] systemd[1]: Listening on Journal Socket (/dev/log).
[[0;32m  OK  [0m] Listening on Journal Socket (/dev/log).
[    5.012137] systemd[1]: Reached target Encrypted Volumes.
[[0;32m  OK  [0m] Reached target Encrypted Volumes.
[    5.015614] systemd[1]: Listening on LVM2 poll daemon socket.
[[0;32m  OK  [0m] Listening on LVM2 poll daemon socket.
[    5.018983] systemd[1]: Listening on Journal Socket.
[[0;32m  OK  [0m] Listening on Journal Socket.
[    5.022145] systemd[1]: Listening on Syslog Socket.
[[0;32m  OK  [0m] Listening on Syslog Socket.
[    5.025326] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[[0;32m  OK  [0m] Listening on Device-mapper event daemon FIFOs.
[    5.029129] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[[0;32m  OK  [0m] Started Forward Password Requests to Wall Directory Watch.
[    5.033572] systemd[1]: Created slice System Slice.
[[0;32m  OK  [0m] Created slice System Slice.
[    5.046329] systemd[1]: Mounting Debug File System...
         Mounting Debug File System...
[    5.049821] systemd[1]: Created slice system-serial\x2dgetty.slice.
[[0;32m  OK  [0m] Created slice system-serial\x2dgetty.slice.
[    5.054837] systemd[1]: Starting Nameserver information manager...
         Starting Nameserver information manager...
[    5.061870] systemd[1]: Starting Create list of required static device nodes for the current kernel...
         Starting Create list of required st... nodes for the current kernel...
[    5.070653] systemd[1]: Starting Uncomplicated firewall...
         Starting Uncomplicated firewall...
[    5.076883] systemd[1]: Mounting Huge Pages File System...
         Mounting Huge Pages File System...
[    5.081777] systemd[1]: Listening on udev Kernel Socket.
[[0;32m  OK  [0m] Listening on udev Kernel Socket.
[    5.086529] systemd[1]: Reached target Swap.
[[0;32m  OK  [0m] Reached target Swap.
[    5.090857] systemd[1]: Listening on LVM2 metadata daemon socket.
[[0;32m  OK  [0m] Listening on LVM2 metadata daemon socket.
[    5.096726] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
         Starting Monitoring of LVM2 mirrors... dmeventd or progress polling...
[    5.104279] systemd[1]: Starting Set console keymap...
         Starting Set console keymap...
[    5.109042] systemd[1]: Reached target User and Group Name Lookups.
[[0;32m  OK  [0m] Reached target User and Group Name Lookups.
[    5.115185] systemd[1]: Mounting POSIX Message Queue File System...
         Mounting POSIX Message Queue File System...
[    5.119894] systemd[1]: Listening on fsck to fsckd communication Socket.
[[0;32m  OK  [0m] Listening on fsck to fsckd communication Socket.
[    5.124980] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[[0;32m  OK  [0m] Set up automount Arbitrary Executab...ats File System Automount Point.
[    5.132627] systemd[1]: Listening on udev Control Socket.
[[0;32m  OK  [0m] Listening on udev Control Socket.
[    5.166554] systemd[1]: Starting Load Kernel Modules...
         Starting Load Kernel Modules...
[    5.173184] systemd[1]: Starting File System Check on Root Device...
         Starting File System Check on Root Device...
[    5.179215] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[[0;32m  OK  [0m] Listening on /dev/initctl Compatibility Named Pipe.
[    5.186356] systemd[1]: Created slice User and Session Slice.
[[0;32m  OK  [0m] Created slice User and Session Slice.
[    5.191785] systemd[1]: Reached target Slices.
[    5.195555] 8021q: 802.1Q VLAN Support v1.8
[[0;32m  OK  [0m] Reached target Slices.
[    5.200681] systemd[1]: Mounted POSIX Message Queue File System.
[[0;32m  OK  [0m] Mounted POSIX Message Queue File System.
[    5.207322] systemd[1]: Mounted Huge Pages File System.
[[0;32m  OK  [0m] Mounted Huge Pages File System.
[    5.213036] systemd[1]: Mounted Debug File System.
[[    5.216637] Loading iSCSI transport class v2.0-870.
[0;32m  OK  [0m] Mounted Debug File System.
[    5.220680] systemd[1]: Started Create list of required static device nodes for the current kernel.
[[0;32m  OK  [0m] Started Create list of required sta...ce nodes for the current kernel.
[    5.227704] systemd[1]: Started Uncomplicated firewall.
[[0;32m  OK  [0m] Started Uncomplicated firewall.
[    5.234102] systemd[1]: Started Set console keymap.
[    5.237908] iscsi: registered transport (tcp)
[[0;32m  OK  [0m] Started Set console keymap.
[    5.241620] systemd[1]: Started File System Check on Root Device.
[[0;32m  OK  [0m] Started File System Check on Root Device.
[    5.247646] systemd[1]: Started Nameserver information manager.
[[0;32m  OK  [0m] Started Nameserver information manager.
[    5.281694] iscsi: registered transport (iser)
[    5.287106] systemd[1]: Started Load Kernel Modules.
[[0;32m  OK  [0m] Started Load Kernel Modules.
[    5.334389] systemd[1]: Mounting FUSE Control File System...
         Mounting FUSE Control File System...
[    5.338816] systemd[1]: Starting Apply Kernel Variables...
         Starting Apply Kernel Variables...
[    5.343031] systemd[1]: Started LVM2 metadata daemon.
[[0;32m  OK  [0m] Started LVM2 metadata daemon.
[    5.347403] systemd[1]: Started File System Check Daemon to report status.
[[0;32m  OK  [0m] Started File System Check Daemon to report status.
         Starting Remount Root and Kernel File Systems...
         Starting Create Static Device Nodes in /dev...
[[0;32m  OK  [0m] Mounted FUSE Control File System.
[[0;32m  OK  [0m] Started Apply Kernel Variables.
[[0;32m  OK  [0m] Started Remount Root and Kernel File Systems.
[[0;32m  OK  [0m] Started Create Static Device Nodes in /dev.
         Starting udev Kernel Device Manager...
         Starting udev Coldplug all Devices...
         Starting Load/Save Random Seed...
[[0;32m  OK  [0m] Started Load/Save Random Seed.
[[0;32m  OK  [0m] Started Entropy daemon using the HAVEGE algorithm.
         Starting Journal Service...
[[0;32m  OK  [0m] Started udev Kernel Device Manager.
[[0;32m  OK  [0m] Started udev Coldplug all Devices.
[[0;32m  OK  [0m] Started Dispatch Password Requests to Console Directory Watch.
         Starting udev Wait for Complete Device Initialization...
[[0;32m  OK  [0m] Started Journal Service.
         Starting Flush Journal to Persistent Storage...
[[0;32m  OK  [0m] Started Flush Journal to Persistent Storage.
[[0;32m  OK  [0m] Found device /dev/ttyS0.
[[0;32m  OK  [0m] Listening on Load/Save RF Kill Switch Status /dev/rfkill Watch.
[    5.711498] intel_rapl: no valid rapl domains found in package 0
[[0;32m  OK  [0m] Created slice system-glean.slice.
         Starting Glean for interface lo...
         Starting Glean for interface ens3...
[    5.766364] intel_rapl: no valid rapl domains found in package 0
[[0;32m  OK  [0m] Started Monitoring of LVM2 mirrors,...ng dmeventd or progress polling.
[[0;32m  OK  [0m] Reached target Local File Systems (Pre).
[[0;32m  OK  [0m] Reached target Local File Systems.
         Starting Set console font and keymap...
         Starting Tell Plymouth To Write Out Runtime Data...
         Starting netfilter persistent configuration...
         Starting Initial cloud-init job (pre-networking)...
         Starting Create Volatile Files and Directories...
         Starting Commit a transient machine-id on disk...
[    5.816831] intel_rapl: no valid rapl domains found in package 0
         Starting LSB: AppArmor initialization...
[[0;32m  OK  [0m] Started Tell Plymouth To Write Out Runtime Data.
[[0;32m  OK  [0m] Started Create Volatile Files and Directories.
         Starting Update UTMP about System Boot/Shutdown...
[[0;32m  OK  [0m] Reached target System Time Synchronized.
[[0;32m  OK  [0m] Started Update UTMP about System Boot/Shutdown.
[[0;32m  OK  [0m] Started Commit a transient machine-id on disk.
[[0;32m  OK  [0m] Started udev Wait for Complete Device Initialization.
[[0;32m  OK  [0m] Started netfilter persistent configuration.
[[0;32m  OK  [0m] Started LSB: AppArmor initialization.
[[0;32m  OK  [0m] Started Set console font and keymap.
[[0;32m  OK  [0m] Created slice system-getty.slice.
[[0;32m  OK  [0m] Started Glean for interface lo.
[[0;32m  OK  [0m] Started Glean for interface ens3.
[    5.795647] cloud-init[653]: Cloud-init v. 18.5-21-g8ee294d5-0ubuntu1~16.04.1 running 'init-local' at Wed, 20 Mar 2019 04:14:47 +0000. Up 5.53 seconds.
[[0;32m  OK  [0m] Started Initial cloud-init job (pre-networking).
[[0;32m  OK  [0m] Reached target System Initialization.
         Starting LXD - unix socket.
[[0;32m  OK  [0m] Listening on D-Bus System Message Bus Socket.
[[0;32m  OK  [0m] Started Daily apt download activities.
[[0;32m  OK  [0m] Listening on ACPID Listen Socket.
[[0;32m  OK  [0m] Started Daily Cleanup of Temporary Directories.
[[0;32m  OK  [0m] Listening on UUID daemon activation socket.
         Starting Socket activation for snappy daemon.
[[0;32m  OK  [0m] Reached target Basic System.
         Starting Accounts Service...
         Starting LSB: MD monitoring daemon...
[[0;32m  OK  [0m] Started D-Bus System Message Bus.
         Starting System Logging Service...
[[0;32m  OK  [0m] Started FUSE filesystem for LXC.
[[0;32m  OK  [0m] Started Deferred execution scheduler.
[[0;32m  OK  [0m] Started Regular background program processing daemon.
         Starting Quickly initialize the non...dom number generator at boot....
         Starting OpenSSH Server Key Generation...
[[0;32m  OK  [0m] Started ACPI Events Check.
[[0;32m  OK  [0m] Started ACPI event daemon.
         Starting LSB: Record successful boot for GRUB...
         Starting Login Service...
[[0;32m  OK  [0m] Started Daily apt upgrade and clean activities.
[[0;32m  OK  [0m] Reached target Timers.
         Starting Grow root partition...
[[0;32m  OK  [0m] Reached target Cloud-config availability.
[[0;32m  OK  [0m] Started System Logging Service.
[[0;32m  OK  [0m] Listening on LXD - unix socket.
[[0;32m  OK  [0m] Listening on Socket activation for snappy daemon.
[[0;32m  OK  [0m] Started Quickly initialize the nonb...andom number generator at boot..
[[0;32m  OK  [0m] Started LSB: MD monitoring daemon.
         Starting Authenticate and Authorize Users to Run Privileged Tasks...
[[0;32m  OK  [0m] Reached target Network (Pre).
         Starting Raise network interfaces...
         Starting Snappy daemon...
         Starting LXD - container startup/shutdown...
[[0;32m  OK  [0m] Started LSB: Record successful boot for GRUB.
[[0;32m  OK  [0m] Started Login Service.
[[0;32m  OK  [0m] Started Raise network interfaces.
[[0;32m  OK  [0m] Started Authenticate and Authorize Users to Run Privileged Tasks.
[[0;32m  OK  [0m] Started Accounts Service.
[[0;32m  OK  [0m] Reached target Network.
[[0;32m  OK  [0m] Started Unattended Upgrades Shutdown.
[[0;32m  OK  [0m] Reached target Network is Online.
         Starting Pollinate to seed the pseudo random number generator...
         Starting iSCSI initiator daemon (iscsid)...
         Starting /etc/rc.local Compatibility...
[    6.246010] rc.local[1149]: + set +e
[    6.247871] rc.local[1149]: + sed -i -e 's/^\(DNS[0-9]*=[.0-9]\+\)/#\1/g' '/etc/sysconfig/network-scripts/ifcfg-*'
[    6.251066] rc.local[1149]: sed: can't read /etc/sysconfig/network-scripts/ifcfg-*: No such file or directory
[    6.253870] rc.local[1149]: + sed -i -e 's/^NETCONFIG_DNS_POLICY=.*/NETCONFIG_DNS_POLICY=""/g' /etc/sysconfig/network/config
[    6.254557] rc.local[1149]: sed: can't read /etc/sysconfig/network/config: No such file or directory
[    6.255023] rc.local[1149]: + set -e
[    6.255380] rc.local[1149]: + echo 'nameserver 127.0.0.1'
[    6.255754] rc.local[1149]: + exit 0
[[0;32m  OK  [0m] Started /etc/rc.local Compatibility.
[[0;32m  OK  [0m] Started iSCSI initiator daemon (iscsid).
         Starting Login to default iSCSI targets...
[[0;32m  OK  [0m] Started OpenSSH Server Key Generation.
[[0;32m  OK  [0m] Started Login to default iSCSI targets.
[[0;32m  OK  [0m] Started LXD - container startup/shutdown.
[[0;32m  OK  [0m] Reached target Remote File Systems (Pre).
[[0;32m  OK  [0m] Reached target Remote File Systems.
         Starting LSB: automatic crash report generation...
         Starting LSB: Set the CPU Frequency Scaling governor to "ondemand"...
         Starting LSB: Start NTP daemon...
         Starting Permit User Sessions...
         Starting LSB: daemon to balance interrupts for SMP systems...
         Starting unbound.service...
[[0;32m  OK  [0m] Started Permit User Sessions.
[[0;32m  OK  [0m] Started LSB: Set the CPU Frequency Scaling governor to "ondemand".
         Starting Hold until boot process finishes up...
         Starting Terminate Plymouth Boot Screen...
[[0;32m  OK  [0m] Started Hold until boot process finishes up.
[[0;32m  OK  [0m] Started Terminate Plymouth Boot Screen.
[[0;32m  OK  [0m] Started Serial Getty on ttyS0.
[[0;32m  OK  [0m] Started Getty on tty1.
[[0;32m  OK  [0m] Reached target Login Prompts.
         Starting Set console scheme...
[[0;32m  OK  [0m] Started Grow root partition.
[[0;32m  OK  [0m] Started LSB: automatic crash report generation.
[[0;32m  OK  [0m] Started Set console scheme.
[[0;32m  OK  [0m] Started LSB: Start NTP daemon.
[[0;32m  OK  [0m] Started LSB: daemon to balance interrupts for SMP systems.
[[0;32m  OK  [0m] Started Pollinate to seed the pseudo random number generator.
         Starting OpenBSD Secure Shell server...
[[0;32m  OK  [0m] Started OpenBSD Secure Shell server.
[[0;32m  OK  [0m] Started Snappy daemon.
         Starting Wait until snapd is fully seeded...
[[0;32m  OK  [0m] Started unbound.service.
[[0;32m  OK  [0m] Reached target Host and Network Name Lookups.
[[0;32m  OK  [0m] Started Wait until snapd is fully seeded.
         Starting Apply the settings specified in cloud-config...
[[0;32m  OK  [0m] Reached target Multi-User System.
[[0;32m  OK  [0m] Reached target Graphical Interface.
         Starting Update UTMP about System Runlevel Changes...
[[0;32m  OK  [0m] Started Update UTMP about System Runlevel Changes.
[   11.093129] cloud-init[1372]: Generating locales (this might take a while)...
[   12.116738] cloud-init[1372]:   en_US.UTF-8... done
[   12.118667] cloud-init[1372]: Generation complete.

Ubuntu 16.04.6 LTS ubuntu-xenial-packet-openlab-0000005026 ttyS0

ubuntu-xenial-packet-openlab-0000005026 login: [   12.899474] cloud-init[1372]: Cloud-init v. 18.5-21-g8ee294d5-0ubuntu1~16.04.1 running 'modules:config' at Wed, 20 Mar 2019 04:14:52 +0000. Up 10.96 seconds.
[   13.537742] cloud-init[1528]: Cloud-init v. 18.5-21-g8ee294d5-0ubuntu1~16.04.1 running 'modules:final' at Wed, 20 Mar 2019 04:14:55 +0000. Up 13.38 seconds.
[   13.542306] cloud-init[1528]: 2019-03-20 04:14:55,331 - util.py[WARNING]: Running module ssh-authkey-fingerprints (<module 'cloudinit.config.cc_ssh_authkey_fingerprints' from '/usr/lib/python3/dist-packages/cloudinit/config/cc_ssh_authkey_fingerprints.py'>) failed
<14>Mar 20 04:14:55 ec2: 
<14>Mar 20 04:14:55 ec2: #############################################################
<14>Mar 20 04:14:55 ec2: -----BEGIN SSH HOST KEY FINGERPRINTS-----
<14>Mar 20 04:14:55 ec2: 1024 SHA256:88P7sKheXdXc1ySuJGBSP2viAI7t8W+BghRBZa28fBY root@ubuntu-xenial-packet-openlab-0000005026 (DSA)
<14>Mar 20 04:14:55 ec2: 256 SHA256:iJE6zhPuX8XHW6w7OX+uN6iVhFT4Ydgt3b4ZT03v4oA root@ubuntu-xenial-packet-openlab-0000005026 (ECDSA)
<14>Mar 20 04:14:55 ec2: 256 SHA256:MRItSHT6FrPDz1WiCQ27Xg6lkFnbuqtSrIqXqiAgCIQ root@ubuntu-xenial-packet-openlab-0000005026 (ED25519)
<14>Mar 20 04:14:55 ec2: 2048 SHA256:O1vEzzYaWeQzPNbLc8dDmtebP8hKSBMtLKfQRd76Mns root@ubuntu-xenial-packet-openlab-0000005026 (RSA)
<14>Mar 20 04:14:55 ec2: -----END SSH HOST KEY FINGERPRINTS-----
<14>Mar 20 04:14:55 ec2: #############################################################
-----BEGIN SSH HOST KEY KEYS-----
ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBB7ClSxJdDIbM7DyDEgrSJv58x1EB9ORP1tiSVR7unGo4KeIeAO+R/0HWdP5/xOcSQKw+wvD3SLuGYUxAEu6azY= root@ubuntu-xenial-packet-openlab-0000005026
ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAj5J4XFsN5mKuRWyRmg43omTnb9oVlqpxnGOtNNP8gg root@ubuntu-xenial-packet-openlab-0000005026
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDD6Ug720JSLMCplmsBNR2m0frGD+xVXJ6jTioJ+pGojsnawLifEV72746UIIA/1Hmd8F0Q3hJc/8qHne+Z2eRKHZ3QemLOtqrPvBAFnOct2g/pBvGQDYLbl0uZl/kiKjX7US0sagnekotck4ScKZH4zfFzLtMiiB9nx+wXZdUrRq5POPX5hqlieZdAtOxF1Q+e9jU+bkWrymILD/IM7pzDV4pu2EKJPb6IyyBTuKinhI7R6MdnG+g8tQbrDmwqQ/mINV5ruiKXkTiQtmJtTN42z2gkz6Wyg7LwcY6kf1ZpoJfzHVIXQrL6ZOCVutycNuOYmBs5NOFk5+HsY/ek8asD root@ubuntu-xenial-packet-openlab-0000005026
-----END SSH HOST KEY KEYS-----
[   13.610879] cloud-init[1528]: Cloud-init v. 18.5-21-g8ee294d5-0ubuntu1~16.04.1 finished at Wed, 20 Mar 2019 04:14:55 +0000. Datasource DataSourceConfigDrive [net,ver=2][source=/dev/sr0].  Up 13.58 seconds

Related Job information

Steps to reproduce the issue

Describe how to reproduce the issue: Probabilistic reproduction, try to ping ready packet nodes in OpenLab nodepool, sometime you can find unreachable node.

Additional context

Add any other context about the problem here.

theopenlab / openlab