kata-hypervisor[694477]: cloud-hypervisor: 6.79924672s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742542, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694477]: time="2020-08-20T21:28:13.118007Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989\" exec_id:\"63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989\" " request=/grpc.AgentService/WaitProcess sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694477]: time="2020-08-20T21:28:13.13044142Z" level=debug msg="request end" debug_console=true duration="4.275µs" name=kata-agent pid=56 request=/grpc.AgentService/WaitProcess resp= sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694477]: time="2020-08-20T21:28:13.140517344Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989\" " request=/grpc.AgentService/RemoveContainer sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694477]: time="2020-08-20T21:28:13.152844881Z" level=debug msg="request end" debug_console=true duration=1.980247ms name=kata-agent pid=56 request=/grpc.AgentService/RemoveContainer resp="&Empty{XXX_unrecognized:[],}" sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694477]: cloud-hypervisor: 6.846196732s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742544, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694477]: time="2020-08-20T21:28:13.172274432Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req= request=/grpc.AgentService/DestroySandbox sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694477]: time="2020-08-20T21:28:13.19588545Z" level=info msg="Remove dev from pciDeviceMap" debug_console=true name=kata-agent pid=56 source=agent subsystem=udevlistener uevent-action=remove uevent-devname= uevent-devpath="/devices/virtual/bdi/0:35" uevent-seqnum=769 uevent-subsystem=bdi
kata-hypervisor[694477]: time="2020-08-20T21:28:13.205577253Z" level=debug msg="request end" debug_console=true duration=21.285767ms name=kata-agent pid=56 request=/grpc.AgentService/DestroySandbox resp="&Empty{XXX_unrecognized:[],}" sandbox=63d46b5f61c694b3b78d8812b8669cffd67d9275809cdbf2894cfba7316ab989 source=agent
kata-hypervisor[694927]: cloud-hypervisor: 19.812888ms: INFO:vmm/src/memory_manager.rs:757 -- Created userspace mapping: 0 -> 7f603c000000 80000000
kata-hypervisor[694927]: cloud-hypervisor: 25.254261ms: INFO:vmm/src/memory_manager.rs:757 -- Created userspace mapping: 7fdffe00000 -> 7f5e3c000000 200000000
kata-hypervisor[694927]: cloud-hypervisor: 28.368731ms: INFO:vmm/src/memory_manager.rs:757 -- Created userspace mapping: 7fddfe00000 -> 7f5e1c000000 20000000
kata-hypervisor[694927]: cloud-hypervisor: 72.603563ms: INFO:vmm/src/cpu.rs:762 -- Request to create new vCPUs: desired = 1, max = 8, allocated = 0, present = 0
kata-hypervisor[694927]: cloud-hypervisor: 72.66121ms: INFO:vmm/src/cpu.rs:701 -- Creating vCPU: cpu_id = 0
kata-hypervisor[694927]: cloud-hypervisor: 73.558577ms: INFO:vmm/src/cpu.rs:880 -- Starting vCPUs: desired = 1, allocated = 1, present = 0
kata-hypervisor[694927]: cloud-hypervisor: 73.602094ms: INFO:vmm/src/cpu.rs:798 -- Starting vCPU: cpu_id = 0
kata-hypervisor[694927]: [ 0.000000] Linux version 5.6.0 (eernst@ubuntu) (gcc version 9.3.0 (Ubuntu 9.3.0-10ubuntu2)) #1 SMP Thu Aug 20 11:19:32 PDT 2020
kata-hypervisor[694927]: [ 0.000000] Command line: root=/dev/pmem0p1 panic=1 no_timer_check noreplace-smp rootflags=data=ordered,errors=remount-ro ro rootfstype=ext4 console=ttyS0,115200n8 systemd.log_target=console systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket agent.log=debug initcall_debug agent.debug_console_vport=1026
kata-hypervisor[694927]: [ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
kata-hypervisor[694927]: [ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
kata-hypervisor[694927]: [ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
kata-hypervisor[694927]: [ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
kata-hypervisor[694927]: [ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'compacted' format.
kata-hypervisor[694927]: [ 0.000000] BIOS-provided physical RAM map:
kata-hypervisor[694927]: [ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009ffff] usable
kata-hypervisor[694927]: [ 0.000000] BIOS-e820: [mem 0x00000000000a0000-0x00000000000fffff] reserved
kata-hypervisor[694927]: [ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007fffffff] usable
kata-hypervisor[694927]: [ 0.000000] BIOS-e820: [mem 0x00000000e8000000-0x00000000f7ffffff] reserved
kata-hypervisor[694927]: [ 0.000000] NX (Execute Disable) protection: active
kata-hypervisor[694927]: [ 0.000000] SMBIOS 3.2.0 present.
kata-hypervisor[694927]: [ 0.000000] DMI: Cloud Hypervisor cloud-hypervisor, BIOS 0
kata-hypervisor[694927]: [ 0.000000] Hypervisor detected: KVM
kata-hypervisor[694927]: [ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
kata-hypervisor[694927]: [ 0.000000] kvm-clock: cpu 0, msr 21ed001, primary cpu clock
kata-hypervisor[694927]: [ 0.000000] kvm-clock: using sched offset of 84904925 cycles
kata-hypervisor[694927]: [ 0.000040] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
kata-hypervisor[694927]: [ 0.000096] tsc: Detected 2400.624 MHz processor
kata-hypervisor[694927]: [ 0.001519] last_pfn = 0x80000 max_arch_pfn = 0x400000000
kata-hypervisor[694927]: [ 0.001932] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
kata-hypervisor[694927]: [ 0.013104] Using GB pages for direct mapping
kata-hypervisor[694927]: [ 0.013561] ACPI: Early table checksum verification disabled
kata-hypervisor[694927]: [ 0.013735] ACPI: RSDP 0x00000000000A0000 000024 (v02 CLOUDH)
kata-hypervisor[694927]: [ 0.013779] ACPI: XSDT 0x00000000000A1768 00003C (v01 CLOUDH CHXSDT 00000001 CLDH 00000000)
kata-hypervisor[694927]: [ 0.013804] ACPI: FACP 0x00000000000A1596 000114 (v06 CLOUDH CHFACP 00000001 CLDH 00000000)
kata-hypervisor[694927]: [ 0.013832] ACPI: DSDT 0x00000000000A0024 001572 (v06 CLOUDH CHDSDT 00000001 CLDH 00000000)
kata-hypervisor[694927]: [ 0.013835] ACPI: APIC 0x00000000000A16AA 000082 (v05 CLOUDH CHMADT 00000001 CLDH 00000000)
kata-hypervisor[694927]: [ 0.013837] ACPI: MCFG 0x00000000000A172C 00003C (v01 CLOUDH CHMCFG 00000001 CLDH 00000000)
kata-hypervisor[694927]: [ 0.015507] Zone ranges:
kata-hypervisor[694927]: [ 0.015541] DMA [mem 0x0000000000001000-0x0000000000ffffff]
kata-hypervisor[694927]: [ 0.015543] DMA32 [mem 0x0000000001000000-0x000000007fffffff]
kata-hypervisor[694927]: [ 0.015544] Normal empty
kata-hypervisor[694927]: [ 0.015544] Device empty
kata-hypervisor[694927]: [ 0.015545] Movable zone start for each node
kata-hypervisor[694927]: [ 0.015545] Early memory node ranges
kata-hypervisor[694927]: [ 0.015546] node 0: [mem 0x0000000000001000-0x000000000009ffff]
kata-hypervisor[694927]: [ 0.015568] node 0: [mem 0x0000000000100000-0x000000007fffffff]
kata-hypervisor[694927]: [ 0.015855] Zeroed struct page in unavailable ranges: 97 pages
kata-hypervisor[694927]: [ 0.015865] Initmem setup node 0 [mem 0x0000000000001000-0x000000007fffffff]
kata-hypervisor[694927]: [ 0.204993] ACPI: PM-Timer IO Port: 0xb008
kata-hypervisor[694927]: [ 0.205502] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
kata-hypervisor[694927]: [ 0.205505] ACPI: INT_SRC_OVR (bus 0 bus_irq 4 global_irq 4 dfl dfl)
kata-hypervisor[694927]: [ 0.205507] Using ACPI (MADT) for SMP configuration information
kata-hypervisor[694927]: [ 0.205542] smpboot: Allowing 8 CPUs, 7 hotplug CPUs
kata-hypervisor[694927]: [ 0.205665] KVM setup pv remote TLB flush
kata-hypervisor[694927]: [ 0.205695] KVM setup pv sched yield
kata-hypervisor[694927]: [ 0.205731] [mem 0x80000000-0xe7ffffff] available for PCI devices
kata-hypervisor[694927]: [ 0.205732] Booting paravirtualized kernel on KVM
kata-hypervisor[694927]: [ 0.205733] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
kata-hypervisor[694927]: [ 0.210790] setup_percpu: NR_CPUS:240 nr_cpumask_bits:240 nr_cpu_ids:8 nr_node_ids:1
kata-hypervisor[694927]: [ 0.219686] percpu: Embedded 42 pages/cpu s140184 r0 d31848 u262144
kata-hypervisor[694927]: [ 0.219835] KVM setup async PF for cpu 0
kata-hypervisor[694927]: [ 0.219860] kvm-stealtime: cpu 0, msr 7dc17e40
kata-hypervisor[694927]: [ 0.219863] Built 1 zonelists, mobility grouping on. Total pages: 515977
kata-hypervisor[694927]: [ 0.219864] Kernel command line: root=/dev/pmem0p1 panic=1 no_timer_check noreplace-smp rootflags=data=ordered,errors=remount-ro ro rootfstype=ext4 console=ttyS0,115200n8 systemd.log_target=console systemd.unit=kata-containers.target systemd.mask=systemd-networkd.service systemd.mask=systemd-networkd.socket agent.log=debug initcall_debug agent.debug_console_vport=1026
kata-hypervisor[694927]: [ 0.228530] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
kata-hypervisor[694927]: [ 0.233820] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
kata-hypervisor[694927]: [ 0.234132] mem auto-init: stack:off, heap alloc:off, heap free:off
kata-hypervisor[694927]: [ 0.237271] Memory: 2038932K/2096764K available (10242K kernel code, 494K rwdata, 1372K rodata, 852K init, 2200K bss, 57832K reserved, 0K cma-reserved)
kata-hypervisor[694927]: [ 0.237725] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=8, Nodes=1
kata-hypervisor[694927]: [ 0.238890] rcu: Hierarchical RCU implementation.
kata-hypervisor[694927]: [ 0.238891] rcu: RCU restricting CPUs from NR_CPUS=240 to nr_cpu_ids=8.
kata-hypervisor[694927]: [ 0.238892] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
kata-hypervisor[694927]: [ 0.238893] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=8
kata-hypervisor[694927]: [ 0.238928] NR_IRQS: 15616, nr_irqs: 472, preallocated irqs: 0
kata-hypervisor[694927]: [ 0.239123] rcu: Offload RCU callbacks from CPUs: (none).
kata-hypervisor[694927]: [ 0.239415] random: get_random_bytes called from start_kernel+0x2a4/0x453 with crng_init=0
kata-hypervisor[694927]: [ 0.239939] Console: colour dummy device 80x25
kata-hypervisor[694927]: [ 0.550430] printk: console [ttyS0] enabled
kata-hypervisor[694927]: [ 0.553065] ACPI: Core revision 20200110
kata-hypervisor[694927]: [ 0.555955] APIC: Switch to symmetric I/O mode setup
kata-hypervisor[694927]: [ 0.948923] x2apic enabled
kata-hypervisor[694927]: [ 0.957548] Switched APIC routing to physical x2apic.
kata-hypervisor[694927]: [ 0.961296] KVM setup pv IPIs
kata-hypervisor[694927]: [ 0.964338] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x229a84f4f0c, max_idle_ns: 440795317047 ns
kata-hypervisor[694927]: [ 0.972522] Calibrating delay loop (skipped) preset value.. 4801.24 BogoMIPS (lpj=9602496)
kata-hypervisor[694927]: [ 0.976509] pid_max: default: 32768 minimum: 301
kata-hypervisor[694927]: [ 0.976509] LSM: Security Framework initializing
kata-hypervisor[694927]: [ 0.976509] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
kata-hypervisor[694927]: [ 0.976509] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
kata-hypervisor[694927]: [ 0.976509] x86/cpu: User Mode Instruction Prevention (UMIP) activated
kata-hypervisor[694927]: [ 0.976509] Last level iTLB entries: 4KB 64, 2MB 8, 4MB 8
kata-hypervisor[694927]: [ 0.976509] Last level dTLB entries: 4KB 64, 2MB 0, 4MB 0, 1GB 4
kata-hypervisor[694927]: [ 0.976509] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
kata-hypervisor[694927]: [ 0.976509] Spectre V2 : Mitigation: Enhanced IBRS
kata-hypervisor[694927]: [ 0.976509] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
kata-hypervisor[694927]: [ 0.976509] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
kata-hypervisor[694927]: [ 0.976509] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl and seccomp
kata-hypervisor[694927]: [ 0.976509] Freeing SMP alternatives memory: 28K
kata-hypervisor[694927]: [ 0.976509] smpboot: CPU0: Intel 06/9e (family: 0x6, model: 0x9e, stepping: 0xd)
kata-hypervisor[694927]: [ 0.977216] Performance Events: Skylake events, Intel PMU driver.
kata-hypervisor[694927]: [ 0.980530] ... version: 2
kata-hypervisor[694927]: [ 0.983356] ... bit width: 48
kata-hypervisor[694927]: [ 0.984521] ... generic registers: 4
kata-hypervisor[694927]: [ 0.986938] ... value mask: 0000ffffffffffff
kata-hypervisor[694927]: [ 0.988522] ... max period: 000000007fffffff
kata-hypervisor[694927]: [ 0.991790] ... fixed-purpose events: 3
kata-hypervisor[694927]: [ 0.992521] ... event mask: 000000070000000f
kata-hypervisor[694927]: [ 0.996140] rcu: Hierarchical SRCU implementation.
kata-hypervisor[694927]: [ 0.997822] smp: Bringing up secondary CPUs ...
kata-hypervisor[694927]: [ 1.000523] smp: Brought up 1 node, 1 CPU
kata-hypervisor[694927]: [ 1.003112] smpboot: Max logical packages: 8
kata-hypervisor[694927]: [ 1.004522] smpboot: Total of 1 processors activated (4801.24 BogoMIPS)
kata-hypervisor[694927]: [ 1.009477] devtmpfs: initialized
kata-hypervisor[694927]: [ 1.012813] x86/mm: Memory block size: 128MB
kata-hypervisor[694927]: [ 1.016860] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
kata-hypervisor[694927]: [ 1.020527] futex hash table entries: 2048 (order: 5, 131072 bytes, linear)
kata-hypervisor[694927]: [ 1.025479] thermal_sys: Registered thermal governor 'step_wise'
kata-hypervisor[694927]: [ 1.029693] NET: Registered protocol family 16
kata-hypervisor[694927]: [ 1.032620] cpuidle: using governor menu
kata-hypervisor[694927]: [ 1.035127] ACPI: bus type PCI registered
kata-hypervisor[694927]: [ 1.036551] acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
kata-hypervisor[694927]: [ 1.040691] PCI: Using configuration type 1 for base access
kata-hypervisor[694927]: [ 1.045553] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
kata-hypervisor[694927]: [ 1.048524] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
kata-hypervisor[694927]: [ 1.053404] ACPI: Added _OSI(Module Device)
kata-hypervisor[694927]: [ 1.055921] ACPI: Added _OSI(Processor Device)
kata-hypervisor[694927]: [ 1.056524] ACPI: Added _OSI(3.0 _SCP Extensions)
kata-hypervisor[694927]: [ 1.059306] ACPI: Added _OSI(Processor Aggregator Device)
kata-hypervisor[694927]: [ 1.060522] ACPI: Added _OSI(Linux-Dell-Video)
kata-hypervisor[694927]: [ 1.063325] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
kata-hypervisor[694927]: [ 1.064521] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
kata-hypervisor[694927]: [ 1.068471] ACPI: 1 ACPI AML tables successfully acquired and loaded
kata-hypervisor[694927]: [ 1.069174] ACPI: Interpreter enabled
kata-hypervisor[694927]: [ 1.071352] ACPI: (supports S0 S5)
kata-hypervisor[694927]: [ 1.072522] ACPI: Using IOAPIC for interrupt routing
kata-hypervisor[694927]: [ 1.075738] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
kata-hypervisor[694927]: [ 1.081213] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
kata-hypervisor[694927]: [ 1.084579] acpi PNP0A08:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
kata-hypervisor[694927]: [ 1.088525] acpi PNP0A08:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
kata-hypervisor[694927]: [ 1.092957] acpiphp: Slot [0] registered
kata-hypervisor[694927]: [ 1.095376] acpiphp: Slot [1] registered
kata-hypervisor[694927]: [ 1.096558] acpiphp: Slot [2] registered
kata-hypervisor[694927]: [ 1.098931] acpiphp: Slot [3] registered
kata-hypervisor[694927]: [ 1.100576] acpiphp: Slot [4] registered
kata-hypervisor[694927]: [ 1.102965] acpiphp: Slot [5] registered
kata-hypervisor[694927]: [ 1.104576] acpiphp: Slot [6] registered
kata-hypervisor[694927]: [ 1.107160] acpiphp: Slot [7] registered
kata-hypervisor[694927]: [ 1.108557] acpiphp: Slot [8] registered
kata-hypervisor[694927]: [ 1.110974] acpiphp: Slot [9] registered
kata-hypervisor[694927]: [ 1.112556] acpiphp: Slot [10] registered
kata-hypervisor[694927]: [ 1.114979] acpiphp: Slot [11] registered
kata-hypervisor[694927]: [ 1.116575] acpiphp: Slot [12] registered
kata-hypervisor[694927]: [ 1.119324] acpiphp: Slot [13] registered
kata-hypervisor[694927]: [ 1.120559] acpiphp: Slot [14] registered
kata-hypervisor[694927]: [ 1.122982] acpiphp: Slot [15] registered
kata-hypervisor[694927]: [ 1.124555] acpiphp: Slot [16] registered
kata-hypervisor[694927]: [ 1.126944] acpiphp: Slot [17] registered
kata-hypervisor[694927]: [ 1.128555] acpiphp: Slot [18] registered
kata-hypervisor[694927]: [ 1.131097] acpiphp: Slot [19] registered
kata-hypervisor[694927]: [ 1.132592] acpiphp: Slot [20] registered
kata-hypervisor[694927]: [ 1.134993] acpiphp: Slot [21] registered
kata-hypervisor[694927]: [ 1.136555] acpiphp: Slot [22] registered
kata-hypervisor[694927]: [ 1.139050] acpiphp: Slot [23] registered
kata-hypervisor[694927]: [ 1.140555] acpiphp: Slot [24] registered
kata-hypervisor[694927]: [ 1.142944] acpiphp: Slot [25] registered
kata-hypervisor[694927]: [ 1.144637] acpiphp: Slot [26] registered
kata-hypervisor[694927]: [ 1.147467] acpiphp: Slot [27] registered
kata-hypervisor[694927]: [ 1.148556] acpiphp: Slot [28] registered
kata-hypervisor[694927]: [ 1.151031] acpiphp: Slot [29] registered
kata-hypervisor[694927]: [ 1.152555] acpiphp: Slot [30] registered
kata-hypervisor[694927]: [ 1.155007] acpiphp: Slot [31] registered
kata-hypervisor[694927]: [ 1.156584] PCI host bridge to bus 0000:00
kata-hypervisor[694927]: [ 1.159007] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
kata-hypervisor[694927]: [ 1.160522] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
kata-hypervisor[694927]: [ 1.164522] pci_bus 0000:00: root bus resource [mem 0xc0000000-0xe7ffffff window]
kata-hypervisor[694927]: [ 1.168522] pci_bus 0000:00: root bus resource [mem 0x4e6db5000-0x7ffffffefff window]
kata-hypervisor[694927]: [ 1.172522] pci_bus 0000:00: root bus resource [bus 00-ff]
kata-hypervisor[694927]: [ 1.175849] pci 0000:00:00.0: [8086:0d57] type 00 class 0x060000
kata-hypervisor[694927]: [ 1.176568] pci 0000:00:00.0: calling quirk_mmio_always_on+0x0/0x10 @ 1
kata-hypervisor[694927]: [ 1.180523] pci 0000:00:00.0: quirk_mmio_always_on+0x0/0x10 took 0 usecs
kata-hypervisor[694927]: [ 1.186334] pci 0000:00:01.0: [1af4:1041] type 00 class 0x020000
kata-hypervisor[694927]: [ 1.189101] pci 0000:00:01.0: reg 0x10: [mem 0x7fffff7f000-0x7ffffffefff 64bit]
kata-hypervisor[694927]: [ 1.195290] pci 0000:00:02.0: [1af4:1044] type 00 class 0xffff00
kata-hypervisor[694927]: [ 1.197090] pci 0000:00:02.0: reg 0x10: [mem 0x7ffffeff000-0x7fffff7efff 64bit]
kata-hypervisor[694927]: [ 1.203302] pci 0000:00:03.0: [1af4:105a] type 00 class 0xffff00
kata-hypervisor[694927]: [ 1.205097] pci 0000:00:03.0: reg 0x10: [mem 0x7ffffe7f000-0x7ffffefefff 64bit]
kata-hypervisor[694927]: [ 1.208817] pci 0000:00:03.0: reg 0x18: [mem 0x7fdffe00000-0x7ffffdfffff 64bit]
kata-hypervisor[694927]: [ 1.215484] pci 0000:00:04.0: [1af4:105b] type 00 class 0xffff00
kata-hypervisor[694927]: [ 1.217082] pci 0000:00:04.0: reg 0x10: [mem 0x7fddfd80000-0x7fddfdfffff 64bit]
kata-hypervisor[694927]: [ 1.223244] pci 0000:00:05.0: [1af4:1053] type 00 class 0xffff00
kata-hypervisor[694927]: [ 1.225177] pci 0000:00:05.0: reg 0x10: [mem 0x7fddfd00000-0x7fddfd7ffff 64bit]
kata-hypervisor[694927]: [ 1.232858] vgaarb: loaded
kata-hypervisor[694927]: [ 1.234869] SCSI subsystem initialized
kata-hypervisor[694927]: [ 1.236530] pps_core: LinuxPPS API ver. 1 registered
kata-hypervisor[694927]: [ 1.239429] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
kata-hypervisor[694927]: [ 1.240526] PTP clock support registered
kata-hypervisor[694927]: [ 1.243152] PCI: Using ACPI for IRQ routing
kata-hypervisor[694927]: [ 1.246052] clocksource: Switched to clocksource kvm-clock
kata-hypervisor[694927]: [ 1.248902] pnp: PnP ACPI init
kata-hypervisor[694927]: [ 1.250801] system 00:00: [mem 0xe8000000-0xf7ffffff] has been reserved
kata-hypervisor[694927]: [ 1.255500] pnp: PnP ACPI: found 2 devices
kata-hypervisor[694927]: [ 1.265404] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
kata-hypervisor[694927]: [ 1.270905] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
kata-hypervisor[694927]: [ 1.275080] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
kata-hypervisor[694927]: [ 1.278787] pci_bus 0000:00: resource 6 [mem 0xc0000000-0xe7ffffff window]
kata-hypervisor[694927]: [ 1.282946] pci_bus 0000:00: resource 7 [mem 0x4e6db5000-0x7ffffffefff window]
kata-hypervisor[694927]: [ 1.287210] NET: Registered protocol family 2
kata-hypervisor[694927]: [ 1.291366] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
kata-hypervisor[694927]: [ 1.296789] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
kata-hypervisor[694927]: [ 1.302394] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
kata-hypervisor[694927]: [ 1.309031] TCP: Hash tables configured (established 16384 bind 16384)
kata-hypervisor[694927]: [ 1.313930] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
kata-hypervisor[694927]: [ 1.318978] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
kata-hypervisor[694927]: [ 1.324313] NET: Registered protocol family 1
kata-hypervisor[694927]: [ 1.327388] PCI: CLS 0 bytes, default 64
kata-hypervisor[694927]: [ 1.330260] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x229a84f4f0c, max_idle_ns: 440795317047 ns
kata-hypervisor[694927]: [ 1.336742] clocksource: Switched to clocksource tsc
kata-hypervisor[694927]: [ 1.340860] platform rtc_cmos: registered platform RTC device (no PNP device found)
kata-hypervisor[694927]: [ 1.346231] workingset: timestamp_bits=46 max_order=19 bucket_order=0
kata-hypervisor[694927]: [ 1.355971] fuse: init (API version 7.31)
kata-hypervisor[694927]: [ 1.358799] SGI XFS with security attributes, no debug enabled
kata-hypervisor[694927]: [ 1.364644] 9p: Installing v9fs 9p2000 file system support
kata-hypervisor[694927]: [ 1.368881] NET: Registered protocol family 38
kata-hypervisor[694927]: [ 1.371961] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
kata-hypervisor[694927]: [ 1.378818] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4
kata-hypervisor[694927]: [ 1.384878] virtio-pci 0000:00:01.0: enabling device (0000 -> 0002)
kata-hypervisor[694927]: [ 1.390803] virtio-pci 0000:00:02.0: enabling device (0000 -> 0002)
kata-hypervisor[694927]: [ 1.396966] virtio-pci 0000:00:03.0: enabling device (0000 -> 0002)
kata-hypervisor[694927]: [ 1.458822] virtiofs virtio2: Cache len: 0x200000000 @ 0x7fdffe00000
kata-hypervisor[694927]: [ 2.226382] memmap_init_zone_device initialised 2097152 pages in 760ms
kata-hypervisor[694927]: [ 2.231216] virtio-pci 0000:00:04.0: enabling device (0000 -> 0002)
kata-hypervisor[694927]: [ 2.238616] virtio-pci 0000:00:05.0: enabling device (0000 -> 0002)
kata-hypervisor[694927]: [ 2.244846] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
kata-hypervisor[694927]: [ 2.249499] 00:01: ttyS0 at I/O 0x3f8 (irq = 24, base_baud = 115200) is a 16550A
kata-hypervisor[694927]: [ 2.296851] random: fast init done
kata-hypervisor[694927]: [ 2.301219] brd: module loaded
kata-hypervisor[694927]: [ 2.303401] random: crng init done
kata-hypervisor[694927]: [ 2.312666] loop: module loaded
kata-hypervisor[694927]: [ 2.410525] nd_pmem pfn0.1: unable to guarantee persistence of writes
kata-hypervisor[694927]: [ 2.472711] intel_pstate: CPU model not supported
kata-hypervisor[694927]: [ 2.478621] xt_time: kernel timezone is -0000
kata-hypervisor[694927]: [ 2.481661] IPVS: Registered protocols (TCP, UDP, SCTP, AH, ESP)
kata-hypervisor[694927]: [ 2.485828] memmap_init_zone_device initialised 131072 pages in 72ms
kata-hypervisor[694927]: [ 2.491036] pmem0: p1
kata-hypervisor[694927]: [ 2.492681] pmem0: detected capacity change from 0 to 534773760
kata-hypervisor[694927]: [ 2.496448] IPVS: Connection hash table configured (size=4096, memory=64Kbytes)
kata-hypervisor[694927]: [ 2.502006] IPVS: ipvs loaded.
kata-hypervisor[694927]: [ 2.503880] IPVS: [rr] scheduler registered.
kata-hypervisor[694927]: [ 2.506469] IPVS: [wrr] scheduler registered.
kata-hypervisor[694927]: [ 2.509337] IPVS: [lc] scheduler registered.
kata-hypervisor[694927]: [ 2.511853] IPVS: [wlc] scheduler registered.
kata-hypervisor[694927]: [ 2.514466] IPVS: [fo] scheduler registered.
kata-hypervisor[694927]: [ 2.517481] IPVS: [ovf] scheduler registered.
kata-hypervisor[694927]: [ 2.521049] IPVS: [lblc] scheduler registered.
kata-hypervisor[694927]: [ 2.524200] IPVS: [lblcr] scheduler registered.
kata-hypervisor[694927]: [ 2.527290] IPVS: [dh] scheduler registered.
kata-hypervisor[694927]: [ 2.530218] IPVS: [sh] scheduler registered.
kata-hypervisor[694927]: [ 2.533936] IPVS: [sed] scheduler registered.
kata-hypervisor[694927]: [ 2.536914] IPVS: [nq] scheduler registered.
kata-hypervisor[694927]: [ 2.540101] IPVS: ftp: loaded support on port[0] = 21
kata-hypervisor[694927]: [ 2.543746] IPVS: [sip] pe registered.
kata-hypervisor[694927]: [ 2.547811] ipt_CLUSTERIP: ClusterIP Version 0.8 loaded successfully
kata-hypervisor[694927]: [ 2.552099] Initializing XFRM netlink socket
kata-hypervisor[694927]: [ 2.555232] NET: Registered protocol family 10
kata-hypervisor[694927]: [ 2.559847] Segment Routing with IPv6
kata-hypervisor[694927]: [ 2.562327] NET: Registered protocol family 17
kata-hypervisor[694927]: [ 2.565242] 9pnet: Installing 9P2000 support
kata-hypervisor[694927]: [ 2.568251] NET: Registered protocol family 40
kata-hypervisor[694927]: [ 2.648407] IPI shorthand broadcast: enabled
kata-hypervisor[694927]: [ 2.651988] sched_clock: Marking stable (1918480626, 733345069)->(2811909933, -160084238)
kata-hypervisor[694927]: [ 2.666804] EXT4-fs (pmem0p1): mounted filesystem with ordered data mode. Opts: data=ordered,errors=remount-ro
kata-hypervisor[694927]: [ 2.672267] VFS: Mounted root (ext4 filesystem) readonly on device 259:1.
kata-hypervisor[694927]: [ 2.676253] devtmpfs: mounted
kata-hypervisor[694927]: [ 2.679361] Freeing unused kernel image (initmem) memory: 852K
kata-hypervisor[694927]: [ 2.682519] Write protecting the kernel read-only data: 14336k
kata-hypervisor[694927]: [ 2.696296] Freeing unused kernel image (text/rodata gap) memory: 2044K
kata-hypervisor[694927]: [ 2.703413] Freeing unused kernel image (rodata/data gap) memory: 676K
kata-hypervisor[694927]: [ 2.706638] Run /sbin/init as init process
kata-hypervisor[694927]: systemd 219 running in system mode. (+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
kata-hypervisor[694927]: Detected virtualization kvm.
kata-hypervisor[694927]: Detected architecture x86-64.
kata-hypervisor[694927]:
kata-hypervisor[694927]: Welcome to CentOS Linux 7 (Core)!
kata-hypervisor[694927]:
kata-hypervisor[694927]: No hostname configured.
kata-hypervisor[694927]: Set hostname to <localhost>.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-random-seed.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-udevd.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-udev-trigger.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-update-utmp.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-tmpfiles-setup.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-journald.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-journal-flush.service, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-udevd-kernel.socket, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-journald.socket, ignoring: Unit not found.
kata-hypervisor[694927]: Cannot add dependency job for unit systemd-udevd-control.socket, ignoring: Unit not found.
kata-hypervisor[694927]: [ OK ] Set up automount Arbitrary Executab...ats File System Automount Point.
kata-hypervisor[694927]: [ OK ] Started Dispatch Password Requests to Console Directory Watch.
kata-hypervisor[694927]: [ OK ] Reached target Paths.
kata-hypervisor[694927]: [ OK ] Reached target Local Encrypted Volumes.
kata-hypervisor[694927]: [ OK ] Reached target Swap.
kata-hypervisor[694927]: [ OK ] Created slice Root Slice.
kata-hypervisor[694927]: [ OK ] Listening on Delayed Shutdown Socket.
kata-hypervisor[694927]: [ OK ] Listening on /dev/initctl Compatibility Named Pipe.
kata-hypervisor[694927]: [ OK ] Created slice System Slice.
kata-hypervisor[694927]: Mounting FUSE Control File System...
kata-hypervisor[694927]: Starting Apply Kernel Variables...
kata-hypervisor[694927]: Mounting Temporary Directory...
kata-hypervisor[694927]: Mounting Huge Pages File System...
kata-hypervisor[694927]: Mounting POSIX Message Queue File System...
kata-hypervisor[694927]: [ OK ] Reached target Slices.
kata-hypervisor[694927]: Starting Create Static Device Nodes in /dev...
kata-hypervisor[694927]: Starting Setup Virtual Console...
kata-hypervisor[694927]: [ OK ] Mounted Temporary Directory.
kata-hypervisor[694927]: [ OK ] Mounted FUSE Control File System.
kata-hypervisor[694927]: [ OK ] Mounted POSIX Message Queue File System.
kata-hypervisor[694927]: [ OK ] Mounted Huge Pages File System.
kata-hypervisor[694927]: [ OK ] Started Apply Kernel Variables.
kata-hypervisor[694927]: [ OK ] Started Create Static Device Nodes in /dev.
kata-hypervisor[694927]: [ OK ] Started Setup Virtual Console.
kata-hypervisor[694927]: [ OK ] Reached target Local File Systems (Pre).
kata-hypervisor[694927]: [ OK ] Reached target Local File Systems.
kata-hypervisor[694927]: [ OK ] Reached target System Initialization.
kata-hypervisor[694927]: [ OK ] Started Daily Cleanup of Temporary Directories.
kata-hypervisor[694927]: [ OK ] Reached target Timers.
kata-hypervisor[694927]: [ OK ] Listening on D-Bus System Message Bus Socket.
kata-hypervisor[694927]: [ OK ] Reached target Sockets.
kata-hypervisor[694927]: [ OK ] Reached target Basic System.
kata-hypervisor[694927]: [ OK ] Started Kata Containers Agent.
kata-hypervisor[694927]: Starting NTP client/server...
kata-hypervisor[694927]: [ OK ] Started NTP client/server.
kata-hypervisor[694927]: [ OK ] Reached target Kata Containers Agent Target.
kata-hypervisor[694927]: Startup finished in 2.018s (kernel) + 353ms (userspace) = 2.371s.
kata-hypervisor[694927]: time="2020-08-20T21:28:29.532857039Z" level=info msg=announce debug_console=true device-handlers="blk,blk-ccw,scsi,nvdimm,mmioblk" name=kata-agent pid=56 source=agent storage-handlers="nvdimm,virtio-fs,local,blk-ccw,mmioblk,scsi,ephemeral,9p,blk" system-memory="2042532 kB" version=1.12.0-alpha0-2b839fef29995b8269317f484fcbb28d704f3431
kata-hypervisor[694927]: time="2020-08-20T21:28:29.543255428Z" level=debug msg="Vsock channel type detected" debug_console=true name=kata-agent pid=56 source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.548233513Z" level=info msg="Started listening for uevents" debug_console=true name=kata-agent pid=56 source=agent subsystem=udevlistener
kata-hypervisor[694927]: time="2020-08-20T21:28:29.555344154Z" level=info msg="agent grpc server starts" debug_console=true name=kata-agent pid=56 source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.560559394Z" level=info msg="Waiting for stopServer signal..." debug_console=true name=kata-agent pid=56 source=agent subsystem=stopserverwatcher
kata-hypervisor[694927]: time="2020-08-20T21:28:29.56772219Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req= request=/grpc.Health/Check source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.572490808Z" level=debug msg="request end" debug_console=true duration=713ns name=kata-agent pid=56 request=/grpc.Health/Check resp="status:SERVING " source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.69035589s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742736, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694927]: time="2020-08-20T21:28:29.58048435Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="interface:<device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" > " request=/grpc.AgentService/UpdateInterface source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.589962868Z" level=info msg="Getting interface from MAC address" debug_console=true interface-name=eth0 mac-address="02:42:ac:11:00:02" name=kata-agent pci-address= pid=56 source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.596963916Z" level=info msg="Link found" debug_console=true interface-name=eth0 link="&{LinkAttrs:{Index:2 MTU:1500 TxQLen:1000 Name:eth0 HardwareAddr:02:42:ac:11:00:02 Flags:broadcast|multicast RawFlags:4098 ParentIndex:0 MasterIndex:0 Namespace:<nil> Alias: Statistics:0xc0001de624 Promisc:0 Xdp:0xc000099460 EncapType:ether Protinfo:<nil> OperState:down NetNsID:0 NumTxQueues:0 NumRxQueues:0 Vfs:[]}}" mac-address="02:42:ac:11:00:02" name=kata-agent pci-address= pid=56 source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.725559689s: INFO:net_util/src/queue_pair.rs:314 -- Listener registered
kata-hypervisor[694927]: cloud-hypervisor: 3.725587833s: INFO:virtio-devices/src/net.rs:97 -- Not signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 3.725618589s: INFO:net_util/src/queue_pair.rs:245 -- Listener unregistered
kata-hypervisor[694927]: cloud-hypervisor: 3.725624578s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 3.725632264s: INFO:virtio-devices/src/net.rs:130 -- Signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 3.74077887s: INFO:net_util/src/queue_pair.rs:314 -- Listener registered
kata-hypervisor[694927]: cloud-hypervisor: 3.740871486s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 13 used_idx = 15 old_idx = 13
kata-hypervisor[694927]: cloud-hypervisor: 3.740883449s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 3.740904309s: INFO:virtio-devices/src/net.rs:95 -- Signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 3.741175734s: INFO:virtio-devices/src/net.rs:97 -- Not signalling RX queue
kata-hypervisor[694927]: time="2020-08-20T21:28:29.629665127Z" level=debug msg="request end" debug_console=true duration=40.824076ms name=kata-agent pid=56 request=/grpc.AgentService/UpdateInterface resp="device:\"eth0\" name:\"eth0\" IPAddresses:<address:\"172.17.0.2\" mask:\"16\" > mtu:1500 hwAddr:\"02:42:ac:11:00:02\" " source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.753378346s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 3.753411517s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: time="2020-08-20T21:28:29.658238974Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="routes:<Routes:<gateway:\"172.17.0.1\" device:\"eth0\" > > " request=/grpc.AgentService/UpdateRoutes source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.668654284Z" level=debug msg="request end" debug_console=true duration=2.230013ms name=kata-agent pid=56 request=/grpc.AgentService/UpdateRoutes resp="Routes:<gateway:\"172.17.0.1\" device:\"eth0\" > " source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.78925307s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742738, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694927]: time="2020-08-20T21:28:29.678592377Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="hostname:\"863f347afcd0\" dns:\"# This file is managed by man:systemd-resolved(8). Do not edit.\" dns:\"#\" dns:\"# This is a dynamic resolv.conf file for connecting local clients directly to\" dns:\"# all known uplink DNS servers. This file lists all configured search domains.\" dns:\"#\" dns:\"# Third party programs must not access this file directly, but only through the\" dns:\"# symlink at /etc/resolv.conf. To manage man:resolv.conf(5) in a different way,\" dns:\"# replace this symlink by a static file or a different symlink.\" dns:\"#\" dns:\"# See man:systemd-resolved.service(8) for details about the supported modes of\" dns:\"# operation for /etc/resolv.conf.\" dns:\"\" dns:\"nameserver 172.16.205.2\" dns:\"search localdomain\" dns:\"\" storages:<driver:\"virtio-fs\" source:\"kataShared\" fstype:\"virtiofs\" options:\"dax\" mount_point:\"/run/kata-containers/shared/containers/\" > storages:<driver:\"ephemeral\" source:\"shm\" fstype:\"tmpfs\" options:\"noexec\" options:\"nosuid\" options:\"nodev\" options:\"mode=1777\" options:\"size=67108864\" mount_point:\"/run/kata-containers/sandbox/shm\" > sandbox_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" " request=/grpc.AgentService/CreateSandbox source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.718544628Z" level=debug debug_console=true mount-destination=/run/kata-containers/shared/containers/ mount-flags=0 mount-fstype=virtiofs mount-options=dax mount-source=kataShared name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: [ 3.579075] fuse_dax_mem_range_init(): dax mapped 2097152 pages. nr_ranges=4096
kata-hypervisor[694927]: time="2020-08-20T21:28:29.737394803Z" level=info msg="Received add uevent" debug_console=true name=kata-agent pid=56 source=agent subsystem=udevlistener uevent-action=add uevent-devname= uevent-devpath="/devices/virtual/bdi/0:35" uevent-seqnum=767 uevent-subsystem=bdi
kata-hypervisor[694927]: time="2020-08-20T21:28:29.746631035Z" level=debug debug_console=true mount-destination=/run/kata-containers/sandbox/shm mount-flags=14 mount-fstype=tmpfs mount-options="mode=1777,size=67108864" mount-source=shm name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.868307235s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 1 used_idx = 2 old_idx = 1
kata-hypervisor[694927]: cloud-hypervisor: 3.868333652s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 3.868342619s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: time="2020-08-20T21:28:29.75668931Z" level=debug debug_console=true mount-destination=/etc/resolv.conf mount-flags=4096 mount-fstype=bind mount-options= mount-source=/run/kata-containers/sandbox/resolv.conf name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.766293877Z" level=debug msg="request end" debug_console=true duration=49.096622ms name=kata-agent pid=56 request=/grpc.AgentService/CreateSandbox resp="&Empty{XXX_unrecognized:[],}" sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.888032276s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742739, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694927]: time="2020-08-20T21:28:29.777072534Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="mem_block_size:true mem_hotplug_probe:true " request=/grpc.AgentService/GetGuestDetails sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:29.785677008Z" level=debug msg="request end" debug_console=true duration="420.517µs" name=kata-agent pid=56 request=/grpc.AgentService/GetGuestDetails resp="mem_block_size_bytes:134217728 agent_details:<version:\"1.12.0-alpha0-2b839fef29995b8269317f484fcbb28d704f3431\" device_handlers:\"blk\" device_handlers:\"blk-ccw\" device_handlers:\"scsi\" device_handlers:\"nvdimm\" device_handlers:\"mmioblk\" storage_handlers:\"virtio-fs\" storage_handlers:\"local\" storage_handlers:\"nvdimm\" storage_handlers:\"ephemeral\" storage_handlers:\"9p\" storage_handlers:\"blk\" storage_handlers:\"blk-ccw\" storage_handlers:\"mmioblk\" storage_handlers:\"scsi\" > " sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: cloud-hypervisor: 3.922379465s: WARN:virtio-devices/src/vsock/csm/connection.rs:306 -- vsock: error writing to local stream (lp=1073742740, pp=1024): StreamWrite(Os { code: 32, kind: BrokenPipe, message: "Broken pipe" })
kata-hypervisor[694927]: time="2020-08-20T21:28:29.825303336Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" exec_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" OCI:<Version:\"1.0.1-dev\" Process:<Terminal:true User:<AdditionalGids:0 AdditionalGids:1 AdditionalGids:2 AdditionalGids:3 AdditionalGids:4 AdditionalGids:6 AdditionalGids:10 AdditionalGids:11 AdditionalGids:20 AdditionalGids:26 AdditionalGids:27 > Args:\"sh\" Env:\"PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin\" Env:\"HOSTNAME=863f347afcd0\" Env:\"TERM=xterm\" Cwd:\"/\" Capabilities:<Bounding:\"CAP_CHOWN\" Bounding:\"CAP_DAC_OVERRIDE\" Bounding:\"CAP_FSETID\" Bounding:\"CAP_FOWNER\" Bounding:\"CAP_MKNOD\" Bounding:\"CAP_NET_RAW\" Bounding:\"CAP_SETGID\" Bounding:\"CAP_SETUID\" Bounding:\"CAP_SETFCAP\" Bounding:\"CAP_SETPCAP\" Bounding:\"CAP_NET_BIND_SERVICE\" Bounding:\"CAP_SYS_CHROOT\" Bounding:\"CAP_KILL\" Bounding:\"CAP_AUDIT_WRITE\" Effective:\"CAP_CHOWN\" Effective:\"CAP_DAC_OVERRIDE\" Effective:\"CAP_FSETID\" Effective:\"CAP_FOWNER\" Effective:\"CAP_MKNOD\" Effective:\"CAP_NET_RAW\" Effective:\"CAP_SETGID\" Effective:\"CAP_SETUID\" Effective:\"CAP_SETFCAP\" Effective:\"CAP_SETPCAP\" Effective:\"CAP_NET_BIND_SERVICE\" Effective:\"CAP_SYS_CHROOT\" Effective:\"CAP_KILL\" Effective:\"CAP_AUDIT_WRITE\" Inheritable:\"CAP_CHOWN\" Inheritable:\"CAP_DAC_OVERRIDE\" Inheritable:\"CAP_FSETID\" Inheritable:\"CAP_FOWNER\" Inheritable:\"CAP_MKNOD\" Inheritable:\"CAP_NET_RAW\" Inheritable:\"CAP_SETGID\" Inheritable:\"CAP_SETUID\" Inheritable:\"CAP_SETFCAP\" Inheritable:\"CAP_SETPCAP\" Inheritable:\"CAP_NET_BIND_SERVICE\" Inheritable: \"CAP_SYS_CHROOT\" Inheritable:\"CAP_KILL\" Inheritable:\"CAP_AUDIT_WRITE\" Permitted:\"CAP_CHOWN\" Permitted:\"CAP_DAC_OVERRIDE\" Permitted:\"CAP_FSETID\" Permitted:\"CAP_FOWNER\" Permitted:\"CAP_MKNOD\" Permitted:\"CAP_NET_RAW\" Permitted:\"CAP_SETGID\" Permitted:\"CAP_SETUID\" Permitted:\"CAP_SETFCAP\cloud-hypervisor: 3.99682821s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 2 used_idx = 3 old_idx = 2
kata-hypervisor[694927]: cloud-hypervisor: 3.996852713s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 3.996861463s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: " Permitted:\"CAP_SETPCAP\" Permitted:\"CAP_NET_BIND_SERVICE\" Permitted:\"CAP_SYS_CHROOT\" Permitted:\"CAP_KILL\" Permitted:\"CAP_AUDIT_WRITE\" > ApparmorProfile:\"docker-default\" > Root:<Path:\"/run/kata-containers/shared/containers/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d/rootfs\" > Hostname:\"863f347afcd0\" Mounts:<destination:\"/proc\" source:\"proc\" type:\"proc\" options:\"nosuid\" options:\"noexec\" options:\"nodev\" > Mounts:<destination:\"/dev\" source:\"tmpfs\" type:\"tmpfs\" options:\"nosuid\" options:\"strictatime\" options:\"mode=755\" options:\"size=65536k\" > Mounts:<destination:\"/dev/pts\" source:\"devpts\" type:\"devpts\" options:\"nosuid\" options:\"noexec\" options:\"newinstance\" options:\"ptmxmode=0666\" options:\"mode=0620\" options:\"gid=5\" > Mounts:<destination:\"/sys\" source:\"sysfs\" type:\"sysfs\" options:\"nosuid\" options:\"noexec\" options:\"nodev\" options:\"ro\" > Mounts:<destination:\"/sys/fs/cgroup\" source:\"cgroup\" type:\"cgroup\" options:\"ro\" options:\"nosuid\" options:\"noexec\" options:\"nodev\" > Mounts:<destination:\"/dev/mqueue\" source:\"mqueue\" type:\"mqueue\" options:\"nosuid\" options:\"noexec\" options:\"nodev\" > Mounts:<destination:\"/dev/shm\" source:\"/run/kata-containers/sandbox/shm\" type:\"bind\" options:\"rbind\" > Mounts:<destination:\"/etc/resolv.conf\" source:\"/run/kata-containers/shared/containers/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d-6da62cb082d25a6d-resolv.conf\" type:\"bind\" options:\"rbind\" options:\"rprivate\" > Mounts:<destination:\"/etc/hostname\" source:\"/run/kata-containers/shared/containers/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d-0ac72022aabd8799-hostname\" type:\"bind\" options:\"rbind\" options:\"rprivate\" > Mounts:<destination:\"/etc/hosts\" source:\"/run/kata-containers/shared/containers/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d-866d356a89c01435-hosts\" type:\"bind\" options:\"rbind\" options:\"rprivate\" > Linux:<Resources:<Memory:<> CPU:<> > CgroupsPath:\"/docker/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" Namespaces:<Type:\"mount\" > Namespaces:<Type:\"uts\" > Namespaces:<Type:\"ipc\" > MaskedPaths:\"/proc/asound\" MaskedPaths:\"/proc/acpi\" MaskedPaths:\"/proc/kcore\" MaskedPaths:\"/proc/keys\" MaskedPaths:\"/proc/latency_stats\" MaskedPaths:\"/proc/timer_list\" MaskedPaths:\"/proc/timer_stats\" MaskedPaths:\"/proc/sched_debug\" MaskedPaths:\"/proc/scsi\" MaskedPaths:\"/sys/firmware\" ReadonlyPaths:\"/proc/bus\" ReadonlyPaths:\"/proc/fs\" ReadonlyPaths:\"/proc/irq\" ReadonlyPaths:\"/proc/sys\" ReadonlyPaths:\"/proc/sysrq-trigger\" > > " request=/grpc.AgentService/CreateContainer sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: [ 3.815062] kmem.limit_in_bytes is deprecated and will be removed. Please report your usecase to linux-mm@kvack.org if you depend on this functionality.
kata-hypervisor[694927]: time="2020-08-20T21:28:30.027718585Z" level=debug msg="nsexec:601 nsexec started"
kata-hypervisor[694927]: time="2020-08-20T21:28:30.03140354Z" level=info msg="Received add uevent" debug_console=true name=kata-agent pid=56 source=agent subsystem=udevlistener uevent-action=add uevent-devname= uevent-devpath=/kernel/slab/pid_2 uevent-seqnum=768 uevent-subsystem=slab
kata-hypervisor[694927]: time="2020-08-20T21:28:30.088032698Z" level=debug msg="request end" debug_console=true duration=130.737751ms name=kata-agent pid=56 request=/grpc.AgentService/CreateContainer resp="&Empty{XXX_unrecognized:[],}" sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.096918463Z" level=info msg="ignoring unexpected signal" debug_console=true name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d signal="child exited" source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.10510855Z" level=info msg="ignoring unexpected signal" debug_console=true name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d signal="child exited" source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.118276922Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" exec_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" len:32768 " request=/grpc.AgentService/ReadStdout sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.160241447Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req= request=/grpc.AgentService/OnlineCPUMem sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.169898975Z" level=debug msg="request end" debug_console=true duration="3.062µs" name=kata-agent pid=56 request=/grpc.AgentService/OnlineCPUMem resp="&Empty{XXX_unrecognized:[],}" sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.183000288Z" level=debug msg="connecting vCPUs" debug_console=true name=kata-agent pid=56 range-of-vcpus=0 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.189735883Z" level=debug msg="updating cpuset cgroup" container=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d debug_console=true name=kata-agent pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.200887501Z" level=debug msg="updating cpuset parent cgroup" debug_console=true name=kata-agent path=/sys/fs/cgroup/cpuset/docker/cpuset.cpus pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.209812443Z" level=debug msg="updating cpuset cgroup" debug_console=true name=kata-agent path=/sys/fs/cgroup/cpuset/docker/863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d/cpuset.cpus pid=56 sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.222625814Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" " request=/grpc.AgentService/StartContainer sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.239163993Z" level=debug msg="request end" debug_console=true duration=5.87488ms name=kata-agent pid=56 request=/grpc.AgentService/StartContainer resp="&Empty{XXX_unrecognized:[],}" sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.24827091Z" level=debug msg="log pipe has been closed: EOF"
kata-hypervisor[694927]: cloud-hypervisor: 4.681313174s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 15 used_idx = 16 old_idx = 15
kata-hypervisor[694927]: cloud-hypervisor: 4.681357856s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 4.681368681s: INFO:virtio-devices/src/net.rs:130 -- Signalling RX queue
kata-hypervisor[694927]: time="2020-08-20T21:28:30.685370566Z" level=debug msg="request end" debug_console=true duration=553.912736ms name=kata-agent pid=56 request=/grpc.AgentService/ReadStdout resp="data:\"/ # \\033[6n\" " sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: time="2020-08-20T21:28:30.695784108Z" level=debug msg="new request" debug_console=true name=kata-agent pid=56 req="container_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" exec_id:\"863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d\" len:32768 " request=/grpc.AgentService/ReadStdout sandbox=863f347afcd03c9b40d62090813b2d4de7547e7d9c785303ac9d4e9ceece6e2d source=agent
kata-hypervisor[694927]: cloud-hypervisor: 4.884807644s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 3 used_idx = 5 old_idx = 3
kata-hypervisor[694927]: cloud-hypervisor: 4.884900125s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 4.884965861s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: cloud-hypervisor: 5.653293062s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 5 used_idx = 6 old_idx = 5
kata-hypervisor[694927]: cloud-hypervisor: 5.653389592s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 5.653457997s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: cloud-hypervisor: 5.906587083s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 16 used_idx = 17 old_idx = 16
kata-hypervisor[694927]: cloud-hypervisor: 5.906679145s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 5.906750455s: INFO:virtio-devices/src/net.rs:130 -- Signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 5.907496474s: INFO:virtio-devices/src/net.rs:97 -- Not signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 6.027514955s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 17 used_idx = 18 old_idx = 17
kata-hypervisor[694927]: cloud-hypervisor: 6.027609725s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 6.02768214s: INFO:virtio-devices/src/net.rs:130 -- Signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 8.686940396s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 18 used_idx = 19 old_idx = 18
kata-hypervisor[694927]: cloud-hypervisor: 8.687034998s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 8.687109008s: INFO:virtio-devices/src/net.rs:130 -- Signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 8.687639147s: INFO:virtio-devices/src/net.rs:97 -- Not signalling RX queue
kata-hypervisor[694927]: cloud-hypervisor: 9.39780194s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 6 used_idx = 7 old_idx = 6
kata-hypervisor[694927]: cloud-hypervisor: 9.397893496s: INFO:vm-virtio/src/queue.rs:715 -- Needs notification: true
kata-hypervisor[694927]: cloud-hypervisor: 9.397962439s: INFO:virtio-devices/src/net.rs:115 -- Signalling TX queue
kata-hypervisor[694927]: cloud-hypervisor: 10.113324575s: INFO:virtio-devices/src/vsock/unix/muxer.rs:440 -- vsock: error adding local-init connection: UnixRead(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })
kata-hypervisor[694927]: cloud-hypervisor: 11.293946849s: INFO:virtio-devices/src/vsock/unix/muxer.rs:440 -- vsock: error adding local-init connection: UnixRead(Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" })
kata-hypervisor[694927]: cloud-hypervisor: 14.47685838s: INFO:vm-virtio/src/queue.rs:704 -- used_event = 19 used_idx = 20 old_idx = 19
Created
August 20, 2020 21:30
-
-
Save egernst/eec3723ea6342133ee2528cc334b7d02 to your computer and use it in GitHub Desktop.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment