From: "Richard W.M. Jones" <rjones@redhat.com>
To: qemu-devel@nongnu.org
Subject: [Qemu-devel] Why is SeaBIOS used with -kernel?
Date: Sat, 19 Mar 2016 20:31:24 +0000 [thread overview]
Message-ID: <20160319203124.GB19398@redhat.com> (raw)
[-- Attachment #1: Type: text/plain, Size: 940 bytes --]
I've been analyzing the libguestfs appliance[1] boot time. See
attached file, especially the end of it.
About 50% of the boot time is because of SeaBIOS.
I'm using the qemu -kernel option. I understand that the kernel needs
some BIOS features, eg. video stuff, E820. But kvmtool comes with a
really minimal BIOS that implements a tiny number of calls[2] and is
far faster than SeaBIOS.
Is there something I'm missing, or for Linux + -kernel could we use a
much simpler BIOS?
Rich.
[1] http://libguestfs.org/guestfs-internals.1.html
[2] https://git.kernel.org/cgit/linux/kernel/git/will/kvmtool.git/tree/x86
--
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-p2v converts physical machines to virtual machines. Boot with a
live CD or over the network (PXE) and turn machines into KVM guests.
http://libguestfs.org/virt-v2v
[-- Attachment #2: analysis.txt --]
[-- Type: text/plain, Size: 95924 bytes --]
Linux moo.home.annexia.org 4.4.4-301.fc23.x86_64 #1 SMP Fri Mar 4 17:42:42 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
model name : Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz
Warming up the libguestfs cache ...
Running the tests in 2 passes ...
pass 1: 461 events collected in 2225687928 ns
pass 2: 461 events collected in 2245359074 ns
pass 0
number of events collected 461
elapsed time 2225687928 ns
#0: +97056 [trace] "launch"
#1: +99375 [trace] "version"
#2: +102941 [trace] "version = <struct guestfs_version = major: 1, minor: 33, release: 15, extra: , >"
#3: +104764 [trace] "get_backend"
#4: +106283 [trace] "get_backend = "direct""
#5: +107087 [library] "launch: program=boot-analysis"
#6: +107817 [library] "launch: version=1.33.15"
#7: +108501 [library] "launch: backend registered: unix"
#8: +109093 [library] "launch: backend registered: uml"
#9: +109563 [library] "launch: backend registered: libvirt"
#10: +109974 [library] "launch: backend registered: direct"
#11: +110351 [library] "launch: backend=direct"
#12: +110837 [library] "launch: tmpdir=/home/rjones/d/libguestfs/tmp/libguestfs8sCP3g"
#13: +130042 [library] "launch: umask=0002"
#14: +130664 [library] "launch: euid=1000"
#15: +141444 [trace] "get_backend_setting "force_tcg""
#16: +144353 [trace] "get_backend_setting = NULL (error)"
#17: +149190 [trace] "get_cachedir"
#18: +150661 [trace] "get_cachedir = "/home/rjones/d/libguestfs/tmp""
#19: +160857 [library] "[00000ms] begin building supermin appliance"
#20: +161663 [library] "[00000ms] run supermin"
#21: +163979 [library] "command: run: /usr/bin/supermin"
#22: +164362 [library] "command: run: \ --build"
#23: +164687 [library] "command: run: \ --verbose"
#24: +164988 [library] "command: run: \ --if-newer"
#25: +165486 [library] "command: run: \ --lock /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#26: +166046 [library] "command: run: \ --copy-kernel"
#27: +166438 [library] "command: run: \ -f ext2"
#28: +166825 [library] "command: run: \ --host-cpu x86_64"
#29: +167210 [library] "command: run: \ /home/rjones/d/libguestfs/appliance/supermin.d"
#30: +167639 [library] "command: run: \ -o /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d"
#31: +7977059 [appliance] "supermin: version: 5.1.15"
#32: +7977825 [appliance] "supermin: rpm: detected RPM version 4.13"
#33: +7978229 [appliance] "supermin: package handler: fedora/rpm"
#34: +7978451 [appliance] "supermin: acquiring lock on /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#35: +7980242 [appliance] "supermin: if-newer: output does not need rebuilding"
#36: +10380455 [library] "[00010ms] finished building supermin appliance"
#37: +10400123 [library] "[00010ms] begin testing qemu features"
#38: +10402506 [library] "command: run: /usr/bin/qemu-kvm"
#39: +10402987 [library] "command: run: \ -display none"
#40: +10403324 [library] "command: run: \ -help"
#41: +104765465 [library] "command: run: /usr/bin/qemu-kvm"
#42: +104766714 [library] "command: run: \ -display none"
#43: +104767288 [library] "command: run: \ -version"
#44: +202653873 [library] "qemu version 2.5"
#45: +202657614 [library] "command: run: /usr/bin/qemu-kvm"
#46: +202658496 [library] "command: run: \ -display none"
#47: +202659149 [library] "command: run: \ -machine accel=kvm:tcg"
#48: +202659767 [library] "command: run: \ -device ?"
#49: +298757574 [trace] "get_sockdir"
#50: +298763200 [trace] "get_sockdir = "/run/user/1000""
#51: +299096021 [library] "[00298ms] finished testing qemu features"
#52: +299106806 [trace] "get_backend_setting "gdb""
#53: +299112199 [trace] "get_backend_setting = NULL (error)"
#54: +300843518 [appliance] "[00299ms] /usr/bin/qemu-kvm \"
#55: +300845906 [appliance] " -global virtio-blk-pci.scsi=off \"
#56: +300846753 [appliance] " -nodefconfig \"
#57: +300847651 [appliance] " -enable-fips \"
#58: +300848437 [appliance] " -nodefaults \"
#59: +300849245 [appliance] " -display none \"
#60: +300850119 [appliance] " -machine accel=kvm:tcg \"
#61: +300850938 [appliance] " -cpu host \"
#62: +300851744 [appliance] " -m 500 \"
#63: +300852472 [appliance] " -no-reboot \"
#64: +300853218 [appliance] " -rtc driftfix=slew \"
#65: +300853946 [appliance] " -no-hpet \"
#66: +300854764 [appliance] " -global kvm-pit.lost_tick_policy=discard \"
#67: +300855667 [appliance] " -kernel /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/kernel \"
#68: +300856630 [appliance] " -initrd /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/initrd \"
#69: +300857530 [appliance] " -device virtio-scsi-pci,id=scsi \"
#70: +300858666 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/libguestfs8sCP3g/devnull1,cache=writeback,id=hd0,if=none \"
#71: +300859526 [appliance] " -device scsi-hd,drive=hd0 \"
#72: +300860403 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \"
#73: +300861333 [appliance] " -device scsi-hd,drive=appliance \"
#74: +300862214 [appliance] " -device virtio-serial-pci \"
#75: +300862972 [appliance] " -serial stdio \"
#76: +300863725 [appliance] " -device sga \"
#77: +300864509 [appliance] " -chardev socket,path=/run/user/1000/libguestfsHISXnh/guestfsd.sock,id=channel0 \"
#78: +300865352 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \"
#79: +300866237 [appliance] " -append 'panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1'"
#80: +394940831 [appliance] "WARNING: Image format was not specified for '/home/rjones/d/libguestfs/tmp/libguestfs8sCP3g/devnull1' and probing guessed raw."
#81: +394943216 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted."
#82: +394944138 [appliance] " Specify the 'raw' format explicitly to remove the restrictions."
#83: +460731351 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n"
#84: +720512029 [appliance] "Google, Inc."
#85: +720514529 [appliance] "Serial Graphics Adapter 06/19/15"
#86: +720516269 [appliance] "SGABIOS $Id: sgabios.S 8 2010-04-22 00:03:40Z nlaredo $ (mockbuild@) Fri Jun 19 00:52:18 UTC 2015"
#87: +720518119 [appliance] "Term: 80x24"
#88: +720519624 [appliance] "4 0"
#89: +720521032 [appliance] "\x1b[2J\x0dSeaBIOS (version 1.8.2-20150714_191134-)"
#90: +831045679 [appliance] "\x0dBooting from ROM..."
#91: +1484676723 [appliance] "\x0dProbing EDD (edd=off to disable)... ok"
#92: +1484683728 [appliance] "\x1b[2J[ 0.000000] Initializing cgroup subsys cpuset"
#93: +1564390068 [appliance] "[ 0.000000] Initializing cgroup subsys cpu"
#94: +1564391677 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct"
#95: +1564392523 [appliance] "[ 0.000000] Linux version 4.4.4-301.fc23.x86_64 (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Fri Mar 4 17:42:42 UTC 2016"
#96: +1565551586 [appliance] "[ 0.000000] Command line: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#97: +1566686375 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256"
#98: +1567821975 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'"
#99: +1567824023 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'"
#100: +1568960944 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'"
#101: +1568962466 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format."
#102: +1570098436 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches."
#103: +1570099889 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:"
#104: +1570100738 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable"
#105: +1571236219 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved"
#106: +1571237650 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved"
#107: +1571238489 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3dffff] usable"
#108: +1572375870 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3e0000-0x000000001f3fffff] reserved"
#109: +1572377379 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved"
#110: +1573511176 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved"
#111: +1573512531 [appliance] "[ 0.000000] NX (Execute Disable) protection: active"
#112: +1573513372 [appliance] "[ 0.000000] SMBIOS 2.8 present."
#113: +1573514154 [appliance] "[ 0.000000] Hypervisor detected: KVM"
#114: +1574648609 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3e0 max_arch_pfn = 0x400000000"
#115: +1574650066 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT "
#116: +1574650874 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f64d0-0x000f64df] mapped at [ffff8800000f64d0]"
#117: +1575784326 [appliance] "[ 0.000000] Using GB pages for direct mapping"
#118: +1575785725 [appliance] "[ 0.000000] RAMDISK: [mem 0x1f38a000-0x1f3dffff]"
#119: +1575786474 [appliance] "[ 0.000000] No NUMA configuration found"
#120: +1576912443 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3dffff]"
#121: +1576913522 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f378000-0x1f389fff]"
#122: +1576914317 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00"
#123: +1578047938 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f368001, primary cpu clock"
#124: +1578049370 [appliance] "[ 0.000000] kvm-clock: using sched offset of 1121123956 cycles"
#125: +1578050134 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"
#126: +1579184946 [appliance] "[ 0.000000] Zone ranges:"
#127: +1579186293 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]"
#128: +1580320735 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3dffff]"
#129: +1580322101 [appliance] "[ 0.000000] Normal empty"
#130: +1580323007 [appliance] "[ 0.000000] Movable zone start for each node"
#131: +1580323742 [appliance] "[ 0.000000] Early memory node ranges"
#132: +1581460226 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]"
#133: +1581461580 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3dffff]"
#134: +1581462306 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3dffff]"
#135: +1582595748 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org"
#136: +1582597114 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4"
#137: +1582597993 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU"
#138: +1583731540 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 "
#139: +1583732917 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000"
#140: +1583733687 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)"
#141: +1583734450 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23"
#142: +1584872191 [appliance] "[ 0.000000] Processors: 1"
#143: +1584874323 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs"
#144: +1584875790 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]"
#145: +1586012051 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]"
#146: +1586013496 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]"
#147: +1586014349 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]"
#148: +1587150643 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices"
#149: +1587151970 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM"
#150: +1587152833 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns"
#151: +1588288872 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1"
#152: +1589427436 [appliance] "[ 0.000000] PERCPU: Embedded 34 pages/cpu @ffff88001f000000 s98712 r8192 d32360 u2097152"
#153: +1589428809 [appliance] "[ 0.000000] KVM setup async PF for cpu 0"
#154: +1589429686 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00d900"
#155: +1589430443 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125849"
#156: +1590574603 [appliance] "[ 0.000000] Policy zone: DMA32"
#157: +1590575949 [appliance] "[ 0.000000] Kernel command line: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#158: +1591711162 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)"
#159: +1592845248 [appliance] "[ 0.000000] Memory: 485620K/511480K available (7827K kernel code, 1307K rwdata, 3444K rodata, 1528K init, 1544K bss, 25860K reserved, 0K cma-reserved)"
#160: +1593977835 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1"
#161: +1593979226 [appliance] "[ 0.000000] Hierarchical RCU implementation."
#162: +1593980071 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64."
#163: +1593980907 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1."
#164: +1595108808 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1"
#165: +1595110083 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16"
#166: +1595110857 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs"
#167: +1596239957 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0."
#168: +1596241288 [appliance] "[ 0.000000] Console: colour *CGA 80x25"
#169: +1596242091 [appliance] "[ 0.000000] console [ttyS0] enabled"
#170: +1597420805 [appliance] "[ 0.000000] tsc: Detected 2593.994 MHz processor"
#171: +1597422043 [appliance] "[ 0.041768] Calibrating delay loop (skipped) preset value.. 5187.98 BogoMIPS (lpj=2593994)"
#172: +1597423841 [appliance] "[ 0.042313] pid_max: default: 32768 minimum: 301"
#173: +1598557713 [appliance] "[ 0.042679] Security Framework initialized"
#174: +1598558889 [appliance] "[ 0.042952] Yama: becoming mindful."
#175: +1598559478 [appliance] "[ 0.043185] SELinux: Disabled at boot."
#176: +1598560031 [appliance] "[ 0.043510] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)"
#177: +1599665786 [appliance] "[ 0.044066] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)"
#178: +1599666943 [appliance] "[ 0.044575] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#179: +1600790774 [appliance] "[ 0.045038] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#180: +1600792471 [appliance] "[ 0.045637] Initializing cgroup subsys io"
#181: +1601919376 [appliance] "[ 0.045934] Initializing cgroup subsys memory"
#182: +1601920658 [appliance] "[ 0.046373] Disabling memory control group subsystem"
#183: +1601921283 [appliance] "[ 0.046723] Initializing cgroup subsys devices"
#184: +1603045613 [appliance] "[ 0.047045] Initializing cgroup subsys freezer"
#185: +1603046766 [appliance] "[ 0.047361] Initializing cgroup subsys net_cls"
#186: +1603047390 [appliance] "[ 0.047676] Initializing cgroup subsys perf_event"
#187: +1603047967 [appliance] "[ 0.047999] Initializing cgroup subsys net_prio"
#188: +1604162814 [appliance] "[ 0.048320] Initializing cgroup subsys hugetlb"
#189: +1604163939 [appliance] "[ 0.048633] Initializing cgroup subsys pids"
#190: +1605936583 [appliance] "[ 0.049893] mce: CPU supports 10 MCE banks"
#191: +1605937754 [appliance] "[ 0.050217] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0"
#192: +1605938396 [appliance] "[ 0.050588] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0"
#193: +1614982494 [appliance] "[ 0.058961] Freeing SMP alternatives memory: 28K (ffffffff81ec6000 - ffffffff81ecd000)"
#194: +1617579634 [appliance] "[ 0.061573] ftrace: allocating 29522 entries in 116 pages"
#195: +1638502712 [appliance] "[ 0.082440] x2apic enabled"
#196: +1638504244 [appliance] "[ 0.082839] Switched APIC routing to physical x2apic."
#197: +1639917480 [appliance] "[ 0.083884] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1"
#198: +1639918772 [appliance] "[ 0.084315] smpboot: CPU0: Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz (family: 0x6, model: 0x3d, stepping: 0x4)"
#199: +1641046836 [appliance] "[ 0.085021] Performance Events: 16-deep LBR, Broadwell events, Intel PMU driver."
#200: +1641047685 [appliance] "[ 0.085559] ... version: 2"
#201: +1641048294 [appliance] "[ 0.085822] ... bit width: 48"
#202: +1641048853 [appliance] "[ 0.086090] ... generic registers: 4"
#203: +1642188713 [appliance] "[ 0.086377] ... value mask: 0000ffffffffffff"
#204: +1642189844 [appliance] "[ 0.086723] ... max period: 000000007fffffff"
#205: +1642190474 [appliance] "[ 0.087064] ... fixed-purpose events: 3"
#206: +1643305181 [appliance] "[ 0.087345] ... event mask: 000000070000000f"
#207: +1643306297 [appliance] "[ 0.088129] x86: Booted up 1 node, 1 CPUs"
#208: +1643306907 [appliance] "[ 0.088403] smpboot: Total of 1 processors activated (5187.98 BogoMIPS)"
#209: +1644417578 [appliance] "[ 0.089054] devtmpfs: initialized"
#210: +1646593775 [appliance] "[ 0.090543] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns"
#211: +1646595023 [appliance] "[ 0.091249] atomic64_test: passed for x86-64 platform with CX8 and with SSE"
#212: +1647730726 [appliance] "[ 0.091711] pinctrl core: initialized pinctrl subsystem"
#213: +1647731886 [appliance] "[ 0.092104] RTC time: 20:24:23, date: 03/19/16"
#214: +1647732531 [appliance] "[ 0.092477] NET: Registered protocol family 16"
#215: +1648928412 [appliance] "[ 0.092903] cpuidle: using governor menu"
#216: +1648929587 [appliance] "[ 0.093341] PCI: Using configuration type 1 for base access"
#217: +1650588506 [appliance] "[ 0.094544] ACPI: Interpreter disabled."
#218: +1650589675 [appliance] "[ 0.094872] vgaarb: loaded"
#219: +1650590315 [appliance] "[ 0.095108] SCSI subsystem initialized"
#220: +1650590941 [appliance] "[ 0.095393] usbcore: registered new interface driver usbfs"
#221: +1651720369 [appliance] "[ 0.095775] usbcore: registered new interface driver hub"
#222: +1651722218 [appliance] "[ 0.096140] usbcore: registered new device driver usb"
#223: +1651723272 [appliance] "[ 0.096532] PCI: Probing PCI hardware"
#224: +1651724299 [appliance] "[ 0.096808] PCI host bridge to bus 0000:00"
#225: +1652859284 [appliance] "[ 0.097087] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]"
#226: +1652860564 [appliance] "[ 0.097503] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]"
#227: +1653965462 [appliance] "[ 0.097968] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]"
#228: +1658270908 [appliance] "[ 0.102200] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]"
#229: +1658274529 [appliance] "[ 0.102698] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]"
#230: +1658275180 [appliance] "[ 0.103124] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]"
#231: +1659394050 [appliance] "[ 0.103610] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]"
#232: +1659395216 [appliance] "[ 0.104369] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI"
#233: +1660511396 [appliance] "[ 0.104860] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB"
#234: +1675343712 [appliance] "[ 0.119267] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]"
#235: +1675345382 [appliance] "[ 0.119850] NetLabel: Initializing"
#236: +1675346034 [appliance] "[ 0.120078] NetLabel: domain hash size = 128"
#237: +1675346592 [appliance] "[ 0.120363] NetLabel: protocols = UNLABELED CIPSOv4"
#238: +1676471989 [appliance] "[ 0.120718] NetLabel: unlabeled traffic allowed by default"
#239: +1676473069 [appliance] "[ 0.121161] clocksource: Switched to clocksource kvm-clock"
#240: +1681957428 [appliance] "[ 0.125895] pnp: PnP ACPI: disabled"
#241: +1681959070 [appliance] "[ 0.126920] NET: Registered protocol family 2"
#242: +1683089205 [appliance] "[ 0.127351] TCP established hash table entries: 4096 (order: 3, 32768 bytes)"
#243: +1683090366 [appliance] "[ 0.127819] TCP bind hash table entries: 4096 (order: 4, 65536 bytes)"
#244: +1684191645 [appliance] "[ 0.128268] TCP: Hash tables configured (established 4096 bind 4096)"
#245: +1684213221 [appliance] "[ 0.128847] UDP hash table entries: 256 (order: 1, 8192 bytes)"
#246: +1684213896 [appliance] "[ 0.129245] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)"
#247: +1685326502 [appliance] "[ 0.129710] NET: Registered protocol family 1"
#248: +1685327276 [appliance] "[ 0.130010] pci 0000:00:00.0: Limiting direct PCI/PCI transfers"
#249: +1685327639 [appliance] "[ 0.130422] pci 0000:00:01.0: PIIX3: Enabling Passive Release"
#250: +1686452661 [appliance] "[ 0.130811] pci 0000:00:01.0: Activating ISA DMA hang workarounds"
#251: +1686453430 [appliance] "[ 0.131278] Unpacking initramfs..."
#252: +1687767672 [appliance] "[ 0.131724] Freeing initrd memory: 344K (ffff88001f38a000 - ffff88001f3e0000)"
#253: +1687768544 [appliance] "[ 0.132298] platform rtc_cmos: registered platform RTC device (no PNP device found)"
#254: +1689093961 [appliance] "[ 0.133046] futex hash table entries: 256 (order: 2, 16384 bytes)"
#255: +1689094910 [appliance] "[ 0.133496] audit: initializing netlink subsys (disabled)"
#256: +1689095164 [appliance] "[ 0.133857] audit: type=2000 audit(1458419064.040:1): initialized"
#257: +1690217078 [appliance] "[ 0.134465] Initialise system trusted keyring"
#258: +1690217803 [appliance] "[ 0.134816] HugeTLB registered 1 GB page size, pre-allocated 0 pages"
#259: +1690218075 [appliance] "[ 0.135239] HugeTLB registered 2 MB page size, pre-allocated 0 pages"
#260: +1692581624 [appliance] "[ 0.136545] zbud: loaded"
#261: +1692582396 [appliance] "[ 0.136920] VFS: Disk quotas dquot_6.6.0"
#262: +1692582640 [appliance] "[ 0.137212] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"
#263: +1693946182 [appliance] "[ 0.137935] Key type big_key registered"
#264: +1695787814 [appliance] "[ 0.139728] NET: Registered protocol family 38"
#265: +1695788638 [appliance] "[ 0.140060] Key type asymmetric registered"
#266: +1695788857 [appliance] "[ 0.140333] Asymmetric key parser 'x509' registered"
#267: +1695789023 [appliance] "[ 0.140691] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)"
#268: +1696920526 [appliance] "[ 0.141235] io scheduler noop registered"
#269: +1696921273 [appliance] "[ 0.141496] io scheduler deadline registered"
#270: +1696921450 [appliance] "[ 0.141802] io scheduler cfq registered (default)"
#271: +1698043321 [appliance] "[ 0.142202] pci_hotplug: PCI Hot Plug PCI Core version: 0.5"
#272: +1698044107 [appliance] "[ 0.142565] pciehp: PCI Express Hot Plug Controller Driver version: 0.4"
#273: +1698044318 [appliance] "[ 0.143090] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled"
#274: +1721976002 [appliance] "[ 0.165988] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A"
#275: +1723232005 [appliance] "[ 0.167250] Non-volatile memory driver v1.3"
#276: +1723232658 [appliance] "[ 0.167552] Linux agpgart interface v0.103"
#277: +1724587999 [appliance] "[ 0.168570] scsi host0: ata_piix"
#278: +1724588359 [appliance] "[ 0.168848] scsi host1: ata_piix"
#279: +1724588571 [appliance] "[ 0.169094] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14"
#280: +1724588819 [appliance] "[ 0.169552] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15"
#281: +1725686630 [appliance] "[ 0.170205] libphy: Fixed MDIO Bus: probed"
#282: +1725686951 [appliance] "[ 0.170513] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"
#283: +1726791570 [appliance] "[ 0.170956] ehci-pci: EHCI PCI platform driver"
#284: +1726791847 [appliance] "[ 0.171261] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"
#285: +1726792035 [appliance] "[ 0.171671] ohci-pci: OHCI PCI platform driver"
#286: +1727900392 [appliance] "[ 0.171971] uhci_hcd: USB Universal Host Controller Interface driver"
#287: +1727900963 [appliance] "[ 0.172423] usbcore: registered new interface driver usbserial"
#288: +1727901137 [appliance] "[ 0.172811] usbcore: registered new interface driver usbserial_generic"
#289: +1729004634 [appliance] "[ 0.173244] usbserial: USB Serial support registered for generic"
#290: +1729004947 [appliance] "[ 0.173656] i8042: PNP: No PS/2 controller found. Probing ports directly."
#291: +1730574973 [appliance] "[ 0.174578] serio: i8042 KBD port at 0x60,0x64 irq 1"
#292: +1730575324 [appliance] "[ 0.174913] serio: i8042 AUX port at 0x60,0x64 irq 12"
#293: +1730575507 [appliance] "[ 0.175461] mousedev: PS/2 mouse device common for all mice"
#294: +1731664398 [appliance] "[ 0.175988] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0"
#295: +1732942557 [appliance] "[ 0.176945] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3"
#296: +1732942978 [appliance] "[ 0.177642] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2"
#297: +1734062409 [appliance] "[ 0.178378] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0"
#298: +1734063168 [appliance] "[ 0.178869] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram"
#299: +1735189517 [appliance] "[ 0.179346] device-mapper: uevent: version 1.0.3"
#300: +1735190567 [appliance] "[ 0.179766] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com"
#301: +1736320716 [appliance] "[ 0.180413] hidraw: raw HID events driver (C) Jiri Kosina"
#302: +1736321604 [appliance] "[ 0.180816] usbcore: registered new interface driver usbhid"
#303: +1736321757 [appliance] "[ 0.181179] usbhid: USB HID core driver"
#304: +1737523474 [appliance] "[ 0.181480] drop_monitor: Initializing network drop monitor service"
#305: +1737524334 [appliance] "[ 0.181957] ip_tables: (C) 2000-2006 Netfilter Core Team"
#306: +1737524569 [appliance] "[ 0.182337] Initializing XFRM netlink socket"
#307: +1738772931 [appliance] "[ 0.182736] NET: Registered protocol family 10"
#308: +1738773755 [appliance] "[ 0.183165] mip6: Mobile IPv6"
#309: +1738773992 [appliance] "[ 0.183365] NET: Registered protocol family 17"
#310: +1738774164 [appliance] "[ 0.183774] microcode: CPU0 sig=0x306d4, pf=0x1, revision=0x1"
#311: +1739910131 [appliance] "[ 0.184192] microcode: Microcode Update Driver: v2.01 <tigran@aivazian.fsnet.co.uk>, Peter Oruba"
#312: +1739910880 [appliance] "[ 0.184768] AVX2 version of gcm_enc/dec engaged."
#313: +1741008523 [appliance] "[ 0.185087] AES CTR mode by8 optimization enabled"
#314: +1757695446 [appliance] "[ 0.201639] registered taskstats version 1"
#315: +1757696640 [appliance] "[ 0.201973] Loading compiled-in X.509 certificates"
#316: +1758907668 [appliance] "[ 0.202865] Loaded X.509 cert 'Fedora kernel signing key: ff671496ff3f386a8ef2031bac2201b2edb4da2a'"
#317: +1758908553 [appliance] "[ 0.203496] zswap: loaded using pool lzo/zbud"
#318: +1758908777 [appliance] "[ 0.203916] Magic number: 8:904:447"
#319: +1760021610 [appliance] "[ 0.204255] rtc_cmos rtc_cmos: setting system clock to 2016-03-19 20:24:23 UTC (1458419063)"
#320: +1883240938 [appliance] "[ 0.327173] Freeing unused kernel memory: 1528K (ffffffff81d48000 - ffffffff81ec6000)"
#321: +1883242402 [appliance] "[ 0.327731] Write protecting the kernel read-only data: 12288k"
#322: +1883242626 [appliance] "[ 0.328225] Freeing unused kernel memory: 352K (ffff8800017a8000 - ffff880001800000)"
#323: +1885922945 [appliance] "[ 0.329893] Freeing unused kernel memory: 652K (ffff880001b5d000 - ffff880001c00000)"
#324: +1885924101 [appliance] "supermin: mounting /proc"
#325: +1885924317 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 dietlibc"
#326: +1887118652 [appliance] "supermin: cmdline: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#327: +1887119552 [appliance] "supermin: uptime: 0.27 0.14"
#328: +1888227367 [appliance] "supermin: mounting /sys"
#329: +1888228166 [appliance] "supermin: internal insmod crc32-pclmul.ko"
#330: +1889562959 [appliance] "supermin: internal insmod crc32c-intel.ko"
#331: +1889563774 [appliance] "supermin: internal insmod crct10dif-pclmul.ko"
#332: +1890663856 [appliance] "supermin: internal insmod crc32.ko"
#333: +1891817677 [appliance] "supermin: internal insmod virtio.ko"
#334: +1893524104 [appliance] "supermin: internal insmod virtio_ring.ko"
#335: +1893524905 [appliance] "supermin: internal insmod virtio_blk.ko"
#336: +1894672466 [appliance] "supermin: internal insmod virtio-rng.ko"
#337: +1895840304 [appliance] "supermin: internal insmod virtio_console.ko"
#338: +1897793718 [appliance] "supermin: internal insmod virtio_net.ko"
#339: +1899046048 [appliance] "supermin: internal insmod virtio_scsi.ko"
#340: +1899046839 [appliance] "supermin: internal insmod virtio_balloon.ko"
#341: +1900146680 [appliance] "supermin: internal insmod virtio_input.ko"
#342: +1901240581 [appliance] "supermin: internal insmod virtio_mmio.ko"
#343: +1902341062 [appliance] "supermin: internal insmod virtio_pci.ko"
#344: +1903450918 [appliance] "[ 0.348355] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10"
#345: +1904553627 [appliance] "[ 0.348868] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver"
#346: +1905855077 [appliance] "[ 0.349838] scsi host2: Virtio SCSI HBA"
#347: +1905855945 [appliance] "[ 0.350266] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11"
#348: +1905856243 [appliance] "[ 0.350772] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver"
#349: +1909907211 [appliance] "[ 0.353855] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#350: +1909908494 [appliance] "[ 0.354604] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#351: +1925324057 [appliance] "[ 0.369308] sd 2:0:0:0: Attached scsi generic sg0 type 0"
#352: +1925325343 [appliance] "[ 0.369799] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)"
#353: +1926475148 [appliance] "[ 0.370451] sd 2:0:1:0: Attached scsi generic sg1 type 0"
#354: +1926475686 [appliance] "[ 0.370865] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)"
#355: +1926475929 [appliance] "[ 0.371491] sd 2:0:0:0: [sda] Write Protect is off"
#356: +1927603547 [appliance] "[ 0.371876] sd 2:0:1:0: [sdb] Write Protect is off"
#357: +1927604332 [appliance] "[ 0.372256] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#358: +1928714150 [appliance] "[ 0.372920] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#359: +1930326528 [appliance] "[ 0.374272] Dev sda: unable to read RDB block 8"
#360: +1930327543 [appliance] "[ 0.374606] sda: unable to read partition table"
#361: +1930327968 [appliance] "[ 0.374919] sda: partition table beyond EOD, enabling native capacity"
#362: +1931896087 [appliance] "[ 0.375846] Dev sda: unable to read RDB block 8"
#363: +1931896564 [appliance] "[ 0.376184] sda: unable to read partition table"
#364: +1931896756 [appliance] "[ 0.376484] sda: partition table beyond EOD, truncated"
#365: +1931896971 [appliance] "[ 0.376832] sd 2:0:1:0: [sdb] Attached SCSI disk"
#366: +1932999490 [appliance] "[ 0.377412] sd 2:0:0:0: [sda] Attached SCSI disk"
#367: +1932999869 [appliance] "supermin: internal insmod crc-ccitt.ko"
#368: +1934672292 [appliance] "supermin: internal insmod crc-itu-t.ko"
#369: +1934673332 [appliance] "supermin: internal insmod crc8.ko"
#370: +1935773990 [appliance] "supermin: internal insmod libcrc32c.ko"
#371: +1937440659 [appliance] "supermin: picked /sys/block/sdb/dev as root device"
#372: +1937441654 [appliance] "supermin: creating /dev/root as block special 8:16"
#373: +1937442036 [appliance] "supermin: mounting new root on /root"
#374: +1938727914 [appliance] "[ 0.382706] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem"
#375: +1941295363 [appliance] "[ 0.385272] EXT4-fs (sdb): mounted filesystem without journal. Opts: "
#376: +1941296851 [appliance] "supermin: chroot"
#377: +1947912424 [appliance] "Starting /init script ..."
#378: +2026634598 [appliance] "[ 0.470592] random: systemd-tmpfile urandom read with 78 bits of entropy available"
#379: +2027804195 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m"
#380: +2029093160 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m"
#381: +2029093558 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m"
#382: +2029097127 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m"
#383: +2030220164 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m"
#384: +2030220571 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:33] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#385: +2031595491 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:37] Failed to replace specifiers: /var/log/journal/%m"
#386: +2031595985 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:38] Failed to replace specifiers: /var/log/journal/%m"
#387: +2031596233 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:39] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#388: +2032665234 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd"
#389: +2035829022 [appliance] "starting version 229"
#390: +2107339884 [appliance] "[ 0.551317] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9"
#391: +2107341200 [appliance] "[ 0.551842] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0"
#392: +2127386470 [appliance] "[ 0.571342] intel_rapl: no valid rapl domains found in package 0"
#393: +2163284964 [appliance] "[ 0.607246] random: nonblocking pool is initialized"
#394: +2165510155 [appliance] "[ 0.609480] input: PC Speaker as /devices/platform/pcspkr/input/input4"
#395: +2170014463 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline"
#396: +2170015881 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline"
#397: +2171577224 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline"
#398: +2171578171 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline"
#399: +2173013270 [appliance] "+ guestfs_boot_analysis=1"
#400: +2173014095 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline"
#401: +2173014345 [appliance] "+ eval"
#402: +2174138706 [appliance] "+ grep -sq selinux=1 /proc/cmdline"
#403: +2174139636 [appliance] "+ shopt -s nullglob"
#404: +2174139838 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#405: +2175340218 [appliance] "+ echo 300"
#406: +2175341067 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#407: +2175341309 [appliance] "+ echo 300"
#408: +2175341449 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#409: +2175341603 [appliance] "+ echo noop"
#410: +2175341750 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#411: +2176432219 [appliance] "+ echo noop"
#412: +2176433365 [appliance] "+ shopt -u nullglob"
#413: +2176433657 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host"
#414: +2178502546 [appliance] "+ ip link set dev lo up"
#415: +2178504010 [appliance] "+ test '' = 1"
#416: +2178504335 [appliance] "+ mdadm -As --auto=yes --run"
#417: +2182347657 [appliance] "mdadm: No arrays found in config file or automatically"
#418: +2182349001 [appliance] "+ modprobe dm_mod"
#419: +2183606913 [appliance] "+ lvmetad"
#420: +2185979651 [appliance] "+ lvm vgchange -aay --sysinit"
#421: +2189813889 [appliance] " Configuration setting "global/notify_dbus" unknown."
#422: +2189815065 [appliance] " lvmetad is not active yet, using direct activation during sysinit"
#423: +2192653829 [appliance] "+ ldmtool create all"
#424: +2196483642 [appliance] "["
#425: +2196484840 [appliance] "]"
#426: +2196485000 [appliance] "+ test 1 = 1"
#427: +2196485162 [appliance] "+ test 1 '!=' 1"
#428: +2196485325 [appliance] "+ test '' = 1"
#429: +2196485460 [appliance] "+ cmd=guestfsd"
#430: +2197649210 [appliance] "+ test x '!=' x"
#431: +2197649599 [appliance] "+ test 1 = 1"
#432: +2197649736 [appliance] "+ cmd='guestfsd --verbose'"
#433: +2197649891 [appliance] "+ test '' = 1"
#434: +2197650016 [appliance] "+ echo guestfsd --verbose"
#435: +2197650158 [appliance] "guestfsd --verbose"
#436: +2197650282 [appliance] "+ guestfsd --verbose"
#437: +2204508785 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'"
#438: +2204510368 [appliance] "udevadm --debug settle"
#439: +2206648777 [appliance] "calling: settle"
#440: +2206652890 [launch_done] "launch done callback"
#441: +2206654841 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG"
#442: +2206658453 [library] "[02206ms] appliance is up"
#443: +2206675099 [trace] "launch = 0"
#444: +2206676517 [trace] "close"
#445: +2206677593 [library] "closing guestfs handle 0x564c2a8cd7a0 (state 2)"
#446: +2206688305 [trace] "internal_autosync"
#447: +2209320588 [appliance] "guestfsd: main_loop: new request, len 0x28"
#448: +2209321513 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0"
#449: +2209322505 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0"
#450: +2210463724 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0"
#451: +2210464272 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=97708k,mode=755 freq=0 passno=0"
#452: +2211579272 [appliance] "umount-all: /proc/mounts: fsname=/dev dir=/dev type=devtmpfs opts=rw,relatime,size=242824k,nr_inodes=60706,mode=755 freq=0 passno=0"
#453: +2214058401 [appliance] "fsync /dev/sda"
#454: +2221147592 [trace] "internal_autosync = 0"
#455: +2221149584 [library] "sending SIGTERM to process 18868"
#456: +2225687281 [close] "close callback"
#457: +2225696157 [library] "command: run: rm"
#458: +2225696982 [library] "command: run: \ -rf /home/rjones/d/libguestfs/tmp/libguestfs8sCP3g"
#459: +2226817341 [library] "command: run: rm"
#460: +2226817932 [library] "command: run: \ -rf /run/user/1000/libguestfsHISXnh"
pass 1
number of events collected 461
elapsed time 2245359074 ns
#0: +88342 [trace] "launch"
#1: +89906 [trace] "version"
#2: +92918 [trace] "version = <struct guestfs_version = major: 1, minor: 33, release: 15, extra: , >"
#3: +94119 [trace] "get_backend"
#4: +95678 [trace] "get_backend = "direct""
#5: +96686 [library] "launch: program=boot-analysis"
#6: +97582 [library] "launch: version=1.33.15"
#7: +98186 [library] "launch: backend registered: unix"
#8: +98632 [library] "launch: backend registered: uml"
#9: +99079 [library] "launch: backend registered: libvirt"
#10: +99536 [library] "launch: backend registered: direct"
#11: +99967 [library] "launch: backend=direct"
#12: +100443 [library] "launch: tmpdir=/home/rjones/d/libguestfs/tmp/libguestfsINdKan"
#13: +118231 [library] "launch: umask=0002"
#14: +118896 [library] "launch: euid=1000"
#15: +127149 [trace] "get_backend_setting "force_tcg""
#16: +130902 [trace] "get_backend_setting = NULL (error)"
#17: +136380 [trace] "get_cachedir"
#18: +137987 [trace] "get_cachedir = "/home/rjones/d/libguestfs/tmp""
#19: +148893 [library] "[00000ms] begin building supermin appliance"
#20: +149957 [library] "[00000ms] run supermin"
#21: +152507 [library] "command: run: /usr/bin/supermin"
#22: +153044 [library] "command: run: \ --build"
#23: +153500 [library] "command: run: \ --verbose"
#24: +154175 [library] "command: run: \ --if-newer"
#25: +154812 [library] "command: run: \ --lock /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#26: +155382 [library] "command: run: \ --copy-kernel"
#27: +155932 [library] "command: run: \ -f ext2"
#28: +156428 [library] "command: run: \ --host-cpu x86_64"
#29: +156961 [library] "command: run: \ /home/rjones/d/libguestfs/appliance/supermin.d"
#30: +157535 [library] "command: run: \ -o /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d"
#31: +7971631 [appliance] "supermin: version: 5.1.15"
#32: +7972754 [appliance] "supermin: rpm: detected RPM version 4.13"
#33: +7973571 [appliance] "supermin: package handler: fedora/rpm"
#34: +7973943 [appliance] "supermin: acquiring lock on /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#35: +7986500 [appliance] "supermin: if-newer: output does not need rebuilding"
#36: +10338598 [library] "[00010ms] finished building supermin appliance"
#37: +10358658 [library] "[00010ms] begin testing qemu features"
#38: +10366255 [library] "command: run: /usr/bin/qemu-kvm"
#39: +10367245 [library] "command: run: \ -display none"
#40: +10367729 [library] "command: run: \ -help"
#41: +105568776 [library] "command: run: /usr/bin/qemu-kvm"
#42: +105569684 [library] "command: run: \ -display none"
#43: +105570201 [library] "command: run: \ -version"
#44: +204912517 [library] "qemu version 2.5"
#45: +204915502 [library] "command: run: /usr/bin/qemu-kvm"
#46: +204916205 [library] "command: run: \ -display none"
#47: +204916761 [library] "command: run: \ -machine accel=kvm:tcg"
#48: +204917388 [library] "command: run: \ -device ?"
#49: +306994830 [trace] "get_sockdir"
#50: +306999078 [trace] "get_sockdir = "/run/user/1000""
#51: +307310294 [library] "[00307ms] finished testing qemu features"
#52: +307320819 [trace] "get_backend_setting "gdb""
#53: +307325324 [trace] "get_backend_setting = NULL (error)"
#54: +309055139 [appliance] "[00307ms] /usr/bin/qemu-kvm \"
#55: +309057848 [appliance] " -global virtio-blk-pci.scsi=off \"
#56: +309058347 [appliance] " -nodefconfig \"
#57: +309058675 [appliance] " -enable-fips \"
#58: +309059006 [appliance] " -nodefaults \"
#59: +309059326 [appliance] " -display none \"
#60: +309059643 [appliance] " -machine accel=kvm:tcg \"
#61: +309061645 [appliance] " -cpu host \"
#62: +309062087 [appliance] " -m 500 \"
#63: +309062434 [appliance] " -no-reboot \"
#64: +309062776 [appliance] " -rtc driftfix=slew \"
#65: +309063058 [appliance] " -no-hpet \"
#66: +309063387 [appliance] " -global kvm-pit.lost_tick_policy=discard \"
#67: +309063768 [appliance] " -kernel /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/kernel \"
#68: +309064237 [appliance] " -initrd /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/initrd \"
#69: +309064588 [appliance] " -device virtio-scsi-pci,id=scsi \"
#70: +309064976 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/libguestfsINdKan/devnull1,cache=writeback,id=hd0,if=none \"
#71: +309065345 [appliance] " -device scsi-hd,drive=hd0 \"
#72: +309065741 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \"
#73: +309066215 [appliance] " -device scsi-hd,drive=appliance \"
#74: +309066563 [appliance] " -device virtio-serial-pci \"
#75: +309066884 [appliance] " -serial stdio \"
#76: +309067193 [appliance] " -device sga \"
#77: +309067515 [appliance] " -chardev socket,path=/run/user/1000/libguestfsABLpPt/guestfsd.sock,id=channel0 \"
#78: +309067917 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \"
#79: +309068381 [appliance] " -append 'panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1'"
#80: +403905232 [appliance] "WARNING: Image format was not specified for '/home/rjones/d/libguestfs/tmp/libguestfsINdKan/devnull1' and probing guessed raw."
#81: +403906795 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted."
#82: +403912252 [appliance] " Specify the 'raw' format explicitly to remove the restrictions."
#83: +472490769 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n"
#84: +741331593 [appliance] "Google, Inc."
#85: +741333333 [appliance] "Serial Graphics Adapter 06/19/15"
#86: +741334141 [appliance] "SGABIOS $Id: sgabios.S 8 2010-04-22 00:03:40Z nlaredo $ (mockbuild@) Fri Jun 19 00:52:18 UTC 2015"
#87: +741334803 [appliance] "Term: 80x24"
#88: +741335302 [appliance] "4 0"
#89: +741335821 [appliance] "\x1b[2J\x0dSeaBIOS (version 1.8.2-20150714_191134-)"
#90: +851607087 [appliance] "\x0dBooting from ROM..."
#91: +1498605209 [appliance] "\x0dProbing EDD (edd=off to disable)... ok"
#92: +1498607336 [appliance] "\x1b[2J[ 0.000000] Initializing cgroup subsys cpuset"
#93: +1578556344 [appliance] "[ 0.000000] Initializing cgroup subsys cpu"
#94: +1578557786 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct"
#95: +1578558207 [appliance] "[ 0.000000] Linux version 4.4.4-301.fc23.x86_64 (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Fri Mar 4 17:42:42 UTC 2016"
#96: +1579693960 [appliance] "[ 0.000000] Command line: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#97: +1580826954 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256"
#98: +1581964769 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'"
#99: +1581965730 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'"
#100: +1583100777 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'"
#101: +1583102010 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format."
#102: +1584231905 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches."
#103: +1584233043 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:"
#104: +1584233511 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable"
#105: +1585367817 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved"
#106: +1585368724 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved"
#107: +1585369021 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3dffff] usable"
#108: +1586503833 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3e0000-0x000000001f3fffff] reserved"
#109: +1586504760 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved"
#110: +1587638208 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved"
#111: +1587639086 [appliance] "[ 0.000000] NX (Execute Disable) protection: active"
#112: +1587639506 [appliance] "[ 0.000000] SMBIOS 2.8 present."
#113: +1588782924 [appliance] "[ 0.000000] Hypervisor detected: KVM"
#114: +1588783788 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3e0 max_arch_pfn = 0x400000000"
#115: +1588784214 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT "
#116: +1589917196 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f64d0-0x000f64df] mapped at [ffff8800000f64d0]"
#117: +1589918113 [appliance] "[ 0.000000] Using GB pages for direct mapping"
#118: +1589918530 [appliance] "[ 0.000000] RAMDISK: [mem 0x1f38a000-0x1f3dffff]"
#119: +1591051535 [appliance] "[ 0.000000] No NUMA configuration found"
#120: +1591052734 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3dffff]"
#121: +1591053481 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f378000-0x1f389fff]"
#122: +1592188495 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00"
#123: +1592190485 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f368001, primary cpu clock"
#124: +1592190850 [appliance] "[ 0.000000] kvm-clock: using sched offset of 1126450732 cycles"
#125: +1593323936 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"
#126: +1593335462 [appliance] "[ 0.000000] Zone ranges:"
#127: +1593336036 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]"
#128: +1594471825 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3dffff]"
#129: +1594472774 [appliance] "[ 0.000000] Normal empty"
#130: +1594473193 [appliance] "[ 0.000000] Movable zone start for each node"
#131: +1595607624 [appliance] "[ 0.000000] Early memory node ranges"
#132: +1595608520 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]"
#133: +1595608930 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3dffff]"
#134: +1596757197 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3dffff]"
#135: +1596758218 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org"
#136: +1596758558 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4"
#137: +1597891709 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU"
#138: +1597892592 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 "
#139: +1597892938 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000"
#140: +1597893228 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)"
#141: +1599026696 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23"
#142: +1599027601 [appliance] "[ 0.000000] Processors: 1"
#143: +1599027967 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs"
#144: +1599028299 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]"
#145: +1600161951 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]"
#146: +1600162827 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]"
#147: +1601296449 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]"
#148: +1601297373 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices"
#149: +1601297697 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM"
#150: +1602431621 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns"
#151: +1602432518 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1"
#152: +1603548781 [appliance] "[ 0.000000] PERCPU: Embedded 34 pages/cpu @ffff88001f000000 s98712 r8192 d32360 u2097152"
#153: +1603549667 [appliance] "[ 0.000000] KVM setup async PF for cpu 0"
#154: +1604698847 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00d900"
#155: +1604699774 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125849"
#156: +1604700182 [appliance] "[ 0.000000] Policy zone: DMA32"
#157: +1604700500 [appliance] "[ 0.000000] Kernel command line: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#158: +1606970171 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)"
#159: +1606971332 [appliance] "[ 0.000000] Memory: 485620K/511480K available (7827K kernel code, 1307K rwdata, 3444K rodata, 1528K init, 1544K bss, 25860K reserved, 0K cma-reserved)"
#160: +1608107744 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1"
#161: +1608108658 [appliance] "[ 0.000000] Hierarchical RCU implementation."
#162: +1609246246 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64."
#163: +1609247167 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1."
#164: +1609247587 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1"
#165: +1610381809 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16"
#166: +1610382639 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs"
#167: +1610383021 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0."
#168: +1610383329 [appliance] "[ 0.000000] Console: colour *CGA 80x25"
#169: +1611513704 [appliance] "[ 0.000000] console [ttyS0] enabled"
#170: +1611523387 [appliance] "[ 0.000000] tsc: Detected 2593.994 MHz processor"
#171: +1611525750 [appliance] "[ 0.042262] Calibrating delay loop (skipped) preset value.. 5187.98 BogoMIPS (lpj=2593994)"
#172: +1612652134 [appliance] "[ 0.042843] pid_max: default: 32768 minimum: 301"
#173: +1612653040 [appliance] "[ 0.043193] Security Framework initialized"
#174: +1612653487 [appliance] "[ 0.043472] Yama: becoming mindful."
#175: +1612653880 [appliance] "[ 0.043711] SELinux: Disabled at boot."
#176: +1613794459 [appliance] "[ 0.044068] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)"
#177: +1613795431 [appliance] "[ 0.044604] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)"
#178: +1614925368 [appliance] "[ 0.045121] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#179: +1614926332 [appliance] "[ 0.045559] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#180: +1616045743 [appliance] "[ 0.046187] Initializing cgroup subsys io"
#181: +1616046722 [appliance] "[ 0.046460] Initializing cgroup subsys memory"
#182: +1616047234 [appliance] "[ 0.046887] Disabling memory control group subsystem"
#183: +1617175974 [appliance] "[ 0.047259] Initializing cgroup subsys devices"
#184: +1617176910 [appliance] "[ 0.047557] Initializing cgroup subsys freezer"
#185: +1617177322 [appliance] "[ 0.047855] Initializing cgroup subsys net_cls"
#186: +1617177718 [appliance] "[ 0.048174] Initializing cgroup subsys perf_event"
#187: +1618307939 [appliance] "[ 0.048515] Initializing cgroup subsys net_prio"
#188: +1618308848 [appliance] "[ 0.048818] Initializing cgroup subsys hugetlb"
#189: +1618309245 [appliance] "[ 0.049139] Initializing cgroup subsys pids"
#190: +1620414486 [appliance] "[ 0.050387] mce: CPU supports 10 MCE banks"
#191: +1620415475 [appliance] "[ 0.050707] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0"
#192: +1620415939 [appliance] "[ 0.051085] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0"
#193: +1630064973 [appliance] "[ 0.060050] Freeing SMP alternatives memory: 28K (ffffffff81ec6000 - ffffffff81ecd000)"
#194: +1632649831 [appliance] "[ 0.062646] ftrace: allocating 29522 entries in 116 pages"
#195: +1653444401 [appliance] "[ 0.083393] x2apic enabled"
#196: +1653445645 [appliance] "[ 0.083796] Switched APIC routing to physical x2apic."
#197: +1654838246 [appliance] "[ 0.084840] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1"
#198: +1654839305 [appliance] "[ 0.085289] smpboot: CPU0: Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz (family: 0x6, model: 0x3d, stepping: 0x4)"
#199: +1655960262 [appliance] "[ 0.086006] Performance Events: 16-deep LBR, Broadwell events, Intel PMU driver."
#200: +1655960789 [appliance] "[ 0.086531] ... version: 2"
#201: +1655961291 [appliance] "[ 0.086794] ... bit width: 48"
#202: +1657108178 [appliance] "[ 0.087084] ... generic registers: 4"
#203: +1657109474 [appliance] "[ 0.087359] ... value mask: 0000ffffffffffff"
#204: +1657110234 [appliance] "[ 0.087701] ... max period: 000000007fffffff"
#205: +1657110836 [appliance] "[ 0.088063] ... fixed-purpose events: 3"
#206: +1658223691 [appliance] "[ 0.088330] ... event mask: 000000070000000f"
#207: +1658225233 [appliance] "[ 0.089151] x86: Booted up 1 node, 1 CPUs"
#208: +1659340853 [appliance] "[ 0.089448] smpboot: Total of 1 processors activated (5187.98 BogoMIPS)"
#209: +1659341827 [appliance] "[ 0.090115] devtmpfs: initialized"
#210: +1661568260 [appliance] "[ 0.091530] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns"
#211: +1661569302 [appliance] "[ 0.092268] atomic64_test: passed for x86-64 platform with CX8 and with SSE"
#212: +1662694646 [appliance] "[ 0.092750] pinctrl core: initialized pinctrl subsystem"
#213: +1662695546 [appliance] "[ 0.093153] RTC time: 20:24:26, date: 03/19/16"
#214: +1662695977 [appliance] "[ 0.093539] NET: Registered protocol family 16"
#215: +1663806449 [appliance] "[ 0.093980] cpuidle: using governor menu"
#216: +1663807345 [appliance] "[ 0.094401] PCI: Using configuration type 1 for base access"
#217: +1665652219 [appliance] "[ 0.095616] ACPI: Interpreter disabled."
#218: +1665653139 [appliance] "[ 0.095946] vgaarb: loaded"
#219: +1665653560 [appliance] "[ 0.096187] SCSI subsystem initialized"
#220: +1665653949 [appliance] "[ 0.096475] usbcore: registered new interface driver usbfs"
#221: +1666792431 [appliance] "[ 0.096863] usbcore: registered new interface driver hub"
#222: +1666793353 [appliance] "[ 0.097225] usbcore: registered new device driver usb"
#223: +1666793735 [appliance] "[ 0.097607] PCI: Probing PCI hardware"
#224: +1666794102 [appliance] "[ 0.097887] PCI host bridge to bus 0000:00"
#225: +1667925873 [appliance] "[ 0.098167] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]"
#226: +1667926863 [appliance] "[ 0.098571] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]"
#227: +1667927268 [appliance] "[ 0.099039] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]"
#228: +1673343067 [appliance] "[ 0.103280] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]"
#229: +1673345585 [appliance] "[ 0.103777] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]"
#230: +1673346357 [appliance] "[ 0.104230] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]"
#231: +1674466811 [appliance] "[ 0.104709] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]"
#232: +1674467844 [appliance] "[ 0.105490] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI"
#233: +1675584768 [appliance] "[ 0.105985] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB"
#234: +1689964535 [appliance] "[ 0.119922] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]"
#235: +1689967098 [appliance] "[ 0.120499] NetLabel: Initializing"
#236: +1689967761 [appliance] "[ 0.120728] NetLabel: domain hash size = 128"
#237: +1689968323 [appliance] "[ 0.121053] NetLabel: protocols = UNLABELED CIPSOv4"
#238: +1691088290 [appliance] "[ 0.121401] NetLabel: unlabeled traffic allowed by default"
#239: +1691089981 [appliance] "[ 0.121858] clocksource: Switched to clocksource kvm-clock"
#240: +1697995693 [appliance] "[ 0.127981] pnp: PnP ACPI: disabled"
#241: +1697997632 [appliance] "[ 0.128998] NET: Registered protocol family 2"
#242: +1699112458 [appliance] "[ 0.129415] TCP established hash table entries: 4096 (order: 3, 32768 bytes)"
#243: +1699113625 [appliance] "[ 0.129895] TCP bind hash table entries: 4096 (order: 4, 65536 bytes)"
#244: +1700236700 [appliance] "[ 0.130351] TCP: Hash tables configured (established 4096 bind 4096)"
#245: +1700237620 [appliance] "[ 0.130953] UDP hash table entries: 256 (order: 1, 8192 bytes)"
#246: +1701368207 [appliance] "[ 0.131366] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)"
#247: +1701369177 [appliance] "[ 0.131815] NET: Registered protocol family 1"
#248: +1701370076 [appliance] "[ 0.132122] pci 0000:00:00.0: Limiting direct PCI/PCI transfers"
#249: +1702483982 [appliance] "[ 0.132544] pci 0000:00:01.0: PIIX3: Enabling Passive Release"
#250: +1702484956 [appliance] "[ 0.132936] pci 0000:00:01.0: Activating ISA DMA hang workarounds"
#251: +1702485470 [appliance] "[ 0.133402] Unpacking initramfs..."
#252: +1703589522 [appliance] "[ 0.133881] Freeing initrd memory: 344K (ffff88001f38a000 - ffff88001f3e0000)"
#253: +1703590458 [appliance] "[ 0.134430] platform rtc_cmos: registered platform RTC device (no PNP device found)"
#254: +1704697303 [appliance] "[ 0.135184] futex hash table entries: 256 (order: 2, 16384 bytes)"
#255: +1704698333 [appliance] "[ 0.135602] audit: initializing netlink subsys (disabled)"
#256: +1705808749 [appliance] "[ 0.136001] audit: type=2000 audit(1458419066.282:1): initialized"
#257: +1705809552 [appliance] "[ 0.136568] Initialise system trusted keyring"
#258: +1706944466 [appliance] "[ 0.136937] HugeTLB registered 1 GB page size, pre-allocated 0 pages"
#259: +1706945546 [appliance] "[ 0.137379] HugeTLB registered 2 MB page size, pre-allocated 0 pages"
#260: +1708707540 [appliance] "[ 0.138708] zbud: loaded"
#261: +1708708476 [appliance] "[ 0.139070] VFS: Disk quotas dquot_6.6.0"
#262: +1708708988 [appliance] "[ 0.139358] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"
#263: +1710072737 [appliance] "[ 0.140101] Key type big_key registered"
#264: +1711920499 [appliance] "[ 0.141902] NET: Registered protocol family 38"
#265: +1711921601 [appliance] "[ 0.142223] Key type asymmetric registered"
#266: +1711922113 [appliance] "[ 0.142495] Asymmetric key parser 'x509' registered"
#267: +1711922572 [appliance] "[ 0.142854] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)"
#268: +1713037042 [appliance] "[ 0.143410] io scheduler noop registered"
#269: +1713037914 [appliance] "[ 0.143674] io scheduler deadline registered"
#270: +1713038392 [appliance] "[ 0.143995] io scheduler cfq registered (default)"
#271: +1714157166 [appliance] "[ 0.144399] pci_hotplug: PCI Hot Plug PCI Core version: 0.5"
#272: +1714158085 [appliance] "[ 0.144768] pciehp: PCI Express Hot Plug Controller Driver version: 0.4"
#273: +1715294317 [appliance] "[ 0.145318] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled"
#274: +1738178724 [appliance] "[ 0.168189] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A"
#275: +1739478589 [appliance] "[ 0.169486] Non-volatile memory driver v1.3"
#276: +1739479707 [appliance] "[ 0.169799] Linux agpgart interface v0.103"
#277: +1740837183 [appliance] "[ 0.170827] scsi host0: ata_piix"
#278: +1740838312 [appliance] "[ 0.171121] scsi host1: ata_piix"
#279: +1740838817 [appliance] "[ 0.171365] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14"
#280: +1740839458 [appliance] "[ 0.171818] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15"
#281: +1741948975 [appliance] "[ 0.172507] libphy: Fixed MDIO Bus: probed"
#282: +1741949994 [appliance] "[ 0.172827] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"
#283: +1743066395 [appliance] "[ 0.173299] ehci-pci: EHCI PCI platform driver"
#284: +1743067201 [appliance] "[ 0.173611] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"
#285: +1743067716 [appliance] "[ 0.174032] ohci-pci: OHCI PCI platform driver"
#286: +1744190185 [appliance] "[ 0.174367] uhci_hcd: USB Universal Host Controller Interface driver"
#287: +1744191069 [appliance] "[ 0.174825] usbcore: registered new interface driver usbserial"
#288: +1744191514 [appliance] "[ 0.175232] usbcore: registered new interface driver usbserial_generic"
#289: +1745311011 [appliance] "[ 0.175702] usbserial: USB Serial support registered for generic"
#290: +1745311905 [appliance] "[ 0.176130] i8042: PNP: No PS/2 controller found. Probing ports directly."
#291: +1746416901 [appliance] "[ 0.177094] serio: i8042 KBD port at 0x60,0x64 irq 1"
#292: +1746417700 [appliance] "[ 0.177431] serio: i8042 AUX port at 0x60,0x64 irq 12"
#293: +1747521164 [appliance] "[ 0.178020] mousedev: PS/2 mouse device common for all mice"
#294: +1747522144 [appliance] "[ 0.178549] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0"
#295: +1748624000 [appliance] "[ 0.179544] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3"
#296: +1749740522 [appliance] "[ 0.180276] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2"
#297: +1751057789 [appliance] "[ 0.181056] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0"
#298: +1751058783 [appliance] "[ 0.181537] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram"
#299: +1751059336 [appliance] "[ 0.182007] device-mapper: uevent: version 1.0.3"
#300: +1752170554 [appliance] "[ 0.182432] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com"
#301: +1752171475 [appliance] "[ 0.183078] hidraw: raw HID events driver (C) Jiri Kosina"
#302: +1753291705 [appliance] "[ 0.183492] usbcore: registered new interface driver usbhid"
#303: +1753292462 [appliance] "[ 0.183878] usbhid: USB HID core driver"
#304: +1753293005 [appliance] "[ 0.184171] drop_monitor: Initializing network drop monitor service"
#305: +1754402243 [appliance] "[ 0.184665] ip_tables: (C) 2000-2006 Netfilter Core Team"
#306: +1754403029 [appliance] "[ 0.185067] Initializing XFRM netlink socket"
#307: +1754403502 [appliance] "[ 0.185452] NET: Registered protocol family 10"
#308: +1755513666 [appliance] "[ 0.185896] mip6: Mobile IPv6"
#309: +1755514550 [appliance] "[ 0.186107] NET: Registered protocol family 17"
#310: +1755515005 [appliance] "[ 0.186529] microcode: CPU0 sig=0x306d4, pf=0x1, revision=0x1"
#311: +1756638526 [appliance] "[ 0.186963] microcode: Microcode Update Driver: v2.01 <tigran@aivazian.fsnet.co.uk>, Peter Oruba"
#312: +1756639342 [appliance] "[ 0.187560] AVX2 version of gcm_enc/dec engaged."
#313: +1757732608 [appliance] "[ 0.187904] AES CTR mode by8 optimization enabled"
#314: +1774292059 [appliance] "[ 0.204288] registered taskstats version 1"
#315: +1774293554 [appliance] "[ 0.204603] Loading compiled-in X.509 certificates"
#316: +1775522607 [appliance] "[ 0.205522] Loaded X.509 cert 'Fedora kernel signing key: ff671496ff3f386a8ef2031bac2201b2edb4da2a'"
#317: +1775523720 [appliance] "[ 0.206146] zswap: loaded using pool lzo/zbud"
#318: +1775524249 [appliance] "[ 0.206560] Magic number: 8:904:447"
#319: +1776615754 [appliance] "[ 0.206901] rtc_cmos rtc_cmos: setting system clock to 2016-03-19 20:24:26 UTC (1458419066)"
#320: +1899834142 [appliance] "[ 0.329811] Freeing unused kernel memory: 1528K (ffffffff81d48000 - ffffffff81ec6000)"
#321: +1899835969 [appliance] "[ 0.330370] Write protecting the kernel read-only data: 12288k"
#322: +1899836653 [appliance] "[ 0.330865] Freeing unused kernel memory: 352K (ffff8800017a8000 - ffff880001800000)"
#323: +1902526760 [appliance] "[ 0.332524] Freeing unused kernel memory: 652K (ffff880001b5d000 - ffff880001c00000)"
#324: +1902527912 [appliance] "supermin: mounting /proc"
#325: +1902528424 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 dietlibc"
#326: +1903700620 [appliance] "supermin: cmdline: panic=1 console=ttyS0 udevtimeout=6000 udev.event-timeout=6000 no_timer_check acpi=off printk.time=1 cgroup_disable=memory root=/dev/sdb selinux=0 guestfs_verbose=1 TERM=xterm-256color guestfs_boot_analysis=1"
#327: +1903701422 [appliance] "supermin: uptime: 0.27 0.14"
#328: +1904800827 [appliance] "supermin: mounting /sys"
#329: +1904801564 [appliance] "supermin: internal insmod crc32-pclmul.ko"
#330: +1906130645 [appliance] "supermin: internal insmod crc32c-intel.ko"
#331: +1906131567 [appliance] "supermin: internal insmod crct10dif-pclmul.ko"
#332: +1907219029 [appliance] "supermin: internal insmod crc32.ko"
#333: +1908298803 [appliance] "supermin: internal insmod virtio.ko"
#334: +1909384589 [appliance] "supermin: internal insmod virtio_ring.ko"
#335: +1911134934 [appliance] "supermin: internal insmod virtio_blk.ko"
#336: +1911135677 [appliance] "supermin: internal insmod virtio-rng.ko"
#337: +1912222514 [appliance] "supermin: internal insmod virtio_console.ko"
#338: +1913287906 [appliance] "supermin: internal insmod virtio_net.ko"
#339: +1915581045 [appliance] "supermin: internal insmod virtio_scsi.ko"
#340: +1916666873 [appliance] "supermin: internal insmod virtio_balloon.ko"
#341: +1916667598 [appliance] "supermin: internal insmod virtio_input.ko"
#342: +1917772686 [appliance] "supermin: internal insmod virtio_mmio.ko"
#343: +1918850939 [appliance] "supermin: internal insmod virtio_pci.ko"
#344: +1920841207 [appliance] "[ 0.350827] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10"
#345: +1920842110 [appliance] "[ 0.351341] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver"
#346: +1922318872 [appliance] "[ 0.352322] scsi host2: Virtio SCSI HBA"
#347: +1922319637 [appliance] "[ 0.352709] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11"
#348: +1922320008 [appliance] "[ 0.353237] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver"
#349: +1926506345 [appliance] "[ 0.356482] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#350: +1926508007 [appliance] "[ 0.357293] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#351: +1941735286 [appliance] "[ 0.371697] sd 2:0:0:0: Attached scsi generic sg0 type 0"
#352: +1941737135 [appliance] "[ 0.372347] sd 2:0:1:0: Attached scsi generic sg1 type 0"
#353: +1941737445 [appliance] "[ 0.372797] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)"
#354: +1942832586 [appliance] "[ 0.373588] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)"
#355: +1943931328 [appliance] "[ 0.374267] sd 2:0:1:0: [sdb] Write Protect is off"
#356: +1943931871 [appliance] "[ 0.374602] sd 2:0:0:0: [sda] Write Protect is off"
#357: +1943932055 [appliance] "[ 0.375015] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#358: +1945058902 [appliance] "[ 0.375652] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#359: +1946142611 [appliance] "[ 0.376759] Dev sda: unable to read RDB block 8"
#360: +1946143180 [appliance] "[ 0.377104] sda: unable to read partition table"
#361: +1947252857 [appliance] "[ 0.377427] sda: partition table beyond EOD, enabling native capacity"
#362: +1947253337 [appliance] "[ 0.378152] sd 2:0:1:0: [sdb] Attached SCSI disk"
#363: +1948369443 [appliance] "[ 0.378661] Dev sda: unable to read RDB block 8"
#364: +1948370141 [appliance] "[ 0.378986] sda: unable to read partition table"
#365: +1948370331 [appliance] "[ 0.379290] sda: partition table beyond EOD, truncated"
#366: +1949481499 [appliance] "[ 0.379922] sd 2:0:0:0: [sda] Attached SCSI disk"
#367: +1949482241 [appliance] "supermin: internal insmod crc-ccitt.ko"
#368: +1951190886 [appliance] "supermin: internal insmod crc-itu-t.ko"
#369: +1951192058 [appliance] "supermin: internal insmod crc8.ko"
#370: +1952951762 [appliance] "supermin: internal insmod libcrc32c.ko"
#371: +1952952616 [appliance] "supermin: picked /sys/block/sdb/dev as root device"
#372: +1954066614 [appliance] "supermin: creating /dev/root as block special 8:16"
#373: +1954067396 [appliance] "supermin: mounting new root on /root"
#374: +1954067589 [appliance] "[ 0.385094] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem"
#375: +1957705934 [appliance] "[ 0.387689] EXT4-fs (sdb): mounted filesystem without journal. Opts: "
#376: +1957711226 [appliance] "supermin: chroot"
#377: +1964770744 [appliance] "Starting /init script ..."
#378: +2057477213 [appliance] "[ 0.487433] random: systemd-tmpfile urandom read with 82 bits of entropy available"
#379: +2058797589 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m"
#380: +2060086479 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m"
#381: +2060087195 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m"
#382: +2060087505 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m"
#383: +2061211993 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m"
#384: +2061212343 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:33] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#385: +2062639298 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:37] Failed to replace specifiers: /var/log/journal/%m"
#386: +2062639869 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:38] Failed to replace specifiers: /var/log/journal/%m"
#387: +2062640037 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:39] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#388: +2064805195 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd"
#389: +2067059008 [appliance] "starting version 229"
#390: +2137052680 [appliance] "[ 0.567034] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9"
#391: +2137054745 [appliance] "[ 0.567539] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0"
#392: +2164342152 [appliance] "[ 0.594332] intel_rapl: no valid rapl domains found in package 0"
#393: +2185435472 [appliance] "[ 0.615415] random: nonblocking pool is initialized"
#394: +2192538565 [appliance] "[ 0.622520] input: PC Speaker as /devices/platform/pcspkr/input/input4"
#395: +2197190077 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline"
#396: +2197191974 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline"
#397: +2198655423 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline"
#398: +2198656623 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline"
#399: +2200104858 [appliance] "+ guestfs_boot_analysis=1"
#400: +2200105994 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline"
#401: +2200106415 [appliance] "+ eval"
#402: +2201229477 [appliance] "+ grep -sq selinux=1 /proc/cmdline"
#403: +2201230815 [appliance] "+ shopt -s nullglob"
#404: +2201231171 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#405: +2202373812 [appliance] "+ echo 300"
#406: +2202375057 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#407: +2202376044 [appliance] "+ echo 300"
#408: +2202376324 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#409: +2202376557 [appliance] "+ echo noop"
#410: +2202376837 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#411: +2203484518 [appliance] "+ echo noop"
#412: +2203485424 [appliance] "+ shopt -u nullglob"
#413: +2203485700 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host"
#414: +2205455231 [appliance] "+ ip link set dev lo up"
#415: +2205456930 [appliance] "+ test '' = 1"
#416: +2205457258 [appliance] "+ mdadm -As --auto=yes --run"
#417: +2208984940 [appliance] "mdadm: No arrays found in config file or automatically"
#418: +2208987086 [appliance] "+ modprobe dm_mod"
#419: +2210276415 [appliance] "+ lvmetad"
#420: +2212639128 [appliance] "+ lvm vgchange -aay --sysinit"
#421: +2215852737 [appliance] " Configuration setting "global/notify_dbus" unknown."
#422: +2215854439 [appliance] " lvmetad is not active yet, using direct activation during sysinit"
#423: +2218414676 [appliance] "+ ldmtool create all"
#424: +2221658701 [appliance] "["
#425: +2221660373 [appliance] "]"
#426: +2221660624 [appliance] "+ test 1 = 1"
#427: +2221660871 [appliance] "+ test 1 '!=' 1"
#428: +2221661083 [appliance] "+ test '' = 1"
#429: +2221661302 [appliance] "+ cmd=guestfsd"
#430: +2222804645 [appliance] "+ test x '!=' x"
#431: +2222805648 [appliance] "+ test 1 = 1"
#432: +2222805929 [appliance] "+ cmd='guestfsd --verbose'"
#433: +2222806165 [appliance] "+ test '' = 1"
#434: +2222806353 [appliance] "+ echo guestfsd --verbose"
#435: +2222806589 [appliance] "guestfsd --verbose"
#436: +2222806830 [appliance] "+ guestfsd --verbose"
#437: +2229192787 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'"
#438: +2229194610 [appliance] "udevadm --debug settle"
#439: +2231316033 [appliance] "calling: settle"
#440: +2231321317 [launch_done] "launch done callback"
#441: +2231323092 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG"
#442: +2231328308 [library] "[02231ms] appliance is up"
#443: +2231350150 [trace] "launch = 0"
#444: +2231351178 [trace] "close"
#445: +2231352166 [library] "closing guestfs handle 0x564c2a8cd7a0 (state 2)"
#446: +2231363554 [trace] "internal_autosync"
#447: +2233992986 [appliance] "guestfsd: main_loop: new request, len 0x28"
#448: +2233994297 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0"
#449: +2233994744 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0"
#450: +2235135420 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0"
#451: +2235136263 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=97708k,mode=755 freq=0 passno=0"
#452: +2236272664 [appliance] "umount-all: /proc/mounts: fsname=/dev dir=/dev type=devtmpfs opts=rw,relatime,size=242824k,nr_inodes=60706,mode=755 freq=0 passno=0"
#453: +2238617992 [appliance] "fsync /dev/sda"
#454: +2240396178 [trace] "internal_autosync = 0"
#455: +2240398977 [library] "sending SIGTERM to process 18887"
#456: +2245358223 [close] "close callback"
#457: +2245364966 [library] "command: run: rm"
#458: +2245365846 [library] "command: run: \ -rf /home/rjones/d/libguestfs/tmp/libguestfsINdKan"
#459: +2246591810 [library] "command: run: rm"
#460: +2246592735 [library] "command: run: \ -rf /run/user/1000/libguestfsABLpPt"
Analyzing the results ...
activity 0:
name = run
start - end = 0.0 - 2235430052.0
mean elapsed = 2235430053.0
variance = 96822215069584.0
s.d = 9839828.0
percent = 100.0
activity 1:
name = supermin:build
start - end = 62176.0 - 10266826.5
mean elapsed = 10204651.5
variance = 223397862.2
s.d = 14946.5
percent = 0.5
activity 2:
name = qemu:feature-detect
start - end = 10286691.5 - 303110457.5
mean elapsed = 292823767.0
variance = 17039302481161.0
s.d = 4127869.0
percent = 13.1
activity 3:
name = qemu
start - end = 304859851.0 - 2235430052.0
mean elapsed = 1930570202.0
variance = 32829164146276.0
s.d = 5729674.0
percent = 86.4
activity 4:
name = qemu:overhead
start - end = 304859851.0 - 466518360.0
mean elapsed = 161658510.0
variance = 3146763783744.0
s.d = 1773912.0
percent = 7.2
activity 5:
name = seabios:overhead
start - end = 466518361.0 - 1571382665.0
mean elapsed = 1104864305.0
variance = 1447529015689.0
s.d = 1203133.0
percent = 49.4
activity 6:
name = kernel
start - end = 1571382666.0 - 2235430052.0
mean elapsed = 664047387.0
variance = 7576966411641.0
s.d = 2752629.0
percent = 29.7
activity 7:
name = kernel:overhead
start - end = 1571382666.0 - 1894133670.5
mean elapsed = 322751005.5
variance = 1486476681732.2
s.d = 1219211.5
percent = 14.4
activity 8:
name = supermin:mini-initrd
start - end = 1894133671.5 - 1949411338.5
mean elapsed = 55277668.0
variance = 8999557956.0
s.d = 94866.0
percent = 2.5
activity 9:
name = supermin: internal insmod crc32-pclmul.ko
start - end = 1896422166.0 - 1897754102.0
mean elapsed = 1331937.0
variance = 8156736.0
s.d = 2856.0
percent = 0.1
activity 10:
name = supermin: internal insmod crc32c-intel.ko
start - end = 1897754103.0 - 1897754970.5
mean elapsed = 868.5
variance = 2862.2
s.d = 53.5
percent = 0.0
activity 11:
name = supermin: internal insmod crct10dif-pclmul.ko
start - end = 1897754971.5 - 1898848742.5
mean elapsed = 1093772.0
variance = 39816100.0
s.d = 6310.0
percent = 0.0
activity 12:
name = supermin: internal insmod crc32.ko
start - end = 1898848743.5 - 1899965540.0
mean elapsed = 1116797.5
variance = 1370739552.2
s.d = 37023.5
percent = 0.0
activity 13:
name = supermin: internal insmod virtio.ko
start - end = 1899965541.0 - 1901361646.5
mean elapsed = 1396106.5
variance = 96298812720.2
s.d = 310320.5
percent = 0.1
activity 14:
name = supermin: internal insmod virtio_ring.ko
start - end = 1901361647.5 - 1902237219.5
mean elapsed = 875573.0
variance = 765226051984.0
s.d = 874772.0
percent = 0.0
activity 15:
name = supermin: internal insmod virtio_blk.ko
start - end = 1902237220.5 - 1902811371.5
mean elapsed = 574152.0
variance = 328797881281.0
s.d = 573409.0
percent = 0.0
activity 16:
name = supermin: internal insmod virtio-rng.ko
start - end = 1902811372.5 - 1903938709.0
mean elapsed = 1127337.5
variance = 1640290500.2
s.d = 40500.5
percent = 0.1
activity 17:
name = supermin: internal insmod virtio_console.ko
start - end = 1903938710.0 - 1905448112.0
mean elapsed = 1509403.0
variance = 197145768121.0
s.d = 444011.0
percent = 0.1
activity 18:
name = supermin: internal insmod virtio_net.ko
start - end = 1905448113.0 - 1907220846.5
mean elapsed = 1772734.5
variance = 270820843620.2
s.d = 520404.5
percent = 0.1
activity 19:
name = supermin: internal insmod virtio_scsi.ko
start - end = 1907220847.5 - 1907764156.0
mean elapsed = 543309.5
variance = 294326322842.2
s.d = 542518.5
percent = 0.0
activity 20:
name = supermin: internal insmod virtio_balloon.ko
start - end = 1907764157.0 - 1908314439.0
mean elapsed = 550283.0
variance = 302013995364.0
s.d = 549558.0
percent = 0.0
activity 21:
name = supermin: internal insmod virtio_input.ko
start - end = 1908314440.0 - 1909413933.5
mean elapsed = 1099494.5
variance = 31287242.2
s.d = 5593.5
percent = 0.0
activity 22:
name = supermin: internal insmod virtio_mmio.ko
start - end = 1909413934.5 - 1910503300.5
mean elapsed = 1089367.0
variance = 123520996.0
s.d = 11114.0
percent = 0.0
activity 23:
name = supermin: internal insmod virtio_pci.ko
start - end = 1910503301.5 - 1941148355.0
mean elapsed = 30645054.5
variance = 189131256.2
s.d = 13752.5
percent = 1.4
activity 24:
name = supermin: internal insmod crc-ccitt.ko
start - end = 1941148356.0 - 1942838889.0
mean elapsed = 1690534.0
variance = 328008321.0
s.d = 18111.0
percent = 0.1
activity 25:
name = supermin: internal insmod crc-itu-t.ko
start - end = 1942838890.0 - 1942839995.0
mean elapsed = 1106.0
variance = 4356.0
s.d = 66.0
percent = 0.0
activity 26:
name = supermin: internal insmod crc8.ko
start - end = 1942839996.0 - 1944270176.0
mean elapsed = 1430181.0
variance = 108585407529.0
s.d = 329523.0
percent = 0.1
activity 27:
name = supermin: internal insmod libcrc32c.ko
start - end = 1944270177.0 - 1945103937.5
mean elapsed = 833761.5
variance = 693734903556.2
s.d = 832907.5
percent = 0.0
activity 28:
name = /init
start - end = 1949411339.5 - 2210135132.5
mean elapsed = 260723794.0
variance = 19104845486281.0
s.d = 4370909.0
percent = 11.7
activity 29:
name = bash:overhead
start - end = 1949411339.5 - 1956248884.0
mean elapsed = 6837545.5
variance = 49271790756.2
s.d = 221972.5
percent = 0.3
activity 30:
name = guestfsd
start - end = 2210135133.5 - 2226245496.5
mean elapsed = 16110364.0
variance = 88983486601.0
s.d = 298301.0
percent = 0.7
activity 31:
name = shutdown
start - end = 2218921148.5 - 2235430052.0
mean elapsed = 16508904.5
variance = 6259300957740.2
s.d = 2501859.5
percent = 0.7
libguestfs 1.33.15
Host:
Appliance:
qemu version 2.5
\x1b[2J\x0dSeaBIOS (version 1.8.2-20150714_191134-)
[ 0.000000] Linux version 4.4.4-301.fc23.x86_64 (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Fri Mar 4 17:42:42 UTC 2016
supermin: ext2 mini initrd starting up: 5.1.15 dietlibc
0.000000s: ▲ run mean:2.235430s ±9.8ms (100.0%)
0.000062s: │ ▲ supermin:build mean:0.010205s ±0.0ms (0.5%)
│ │
0.010267s: │ ▼
0.010287s: │ ▲ qemu:feature-detect mean:0.292824s ±4.1ms (13.1%)
│ │
0.303110s: │ ▼
│
0.304860s: │ ▲ ▲ qemu mean:1.930570s ±5.7ms (86.4%) qemu:overhead mean:0.161659s ±1.8ms (7.2%)
│ │ │
0.466518s: │ │ ▼
0.466518s: │ │ ▲ seabios:overhead mean:1.104864s ±1.2ms (49.4%)
│ │ │
1.571383s: │ │ ▼
1.571383s: │ │ ▲ ▲ kernel mean:0.664047s ±2.8ms (29.7%) kernel:overhead mean:0.322751s ±1.2ms (14.4%)
│ │ │ │
1.894134s: │ │ │ ▼
1.894134s: │ │ │ ▲ supermin:mini-initrd mean:0.055278s ±0.1ms (2.5%)
│ │ │ │
1.896422s: │ │ │ │ ▲ supermin: internal insmod crc32-pclmul.ko mean:0.001332s ±0.0ms (0.1%)
│ │ │ │ │
1.897754s: │ │ │ │ ▼
1.897754s: │ │ │ │ ▲ supermin: internal insmod crc32c-intel.ko mean:0.000001s ±0.0ms (0.0%)
1.897755s: │ │ │ │ ▼
1.897755s: │ │ │ │ ▲ supermin: internal insmod crct10dif-pclmul.ko mean:0.001094s ±0.0ms (0.0%)
│ │ │ │ │
1.898849s: │ │ │ │ ▼
1.898849s: │ │ │ │ ▲ supermin: internal insmod crc32.ko mean:0.001117s ±0.0ms (0.0%)
│ │ │ │ │
1.899966s: │ │ │ │ ▼
1.899966s: │ │ │ │ ▲ supermin: internal insmod virtio.ko mean:0.001396s ±0.3ms (0.1%)
│ │ │ │ │
1.901362s: │ │ │ │ ▼
1.901362s: │ │ │ │ ▲ supermin: internal insmod virtio_ring.ko mean:0.000876s ±0.9ms (0.0%)
1.902237s: │ │ │ │ ▼
1.902237s: │ │ │ │ ▲ supermin: internal insmod virtio_blk.ko mean:0.000574s ±0.6ms (0.0%)
1.902811s: │ │ │ │ ▼
1.902811s: │ │ │ │ ▲ supermin: internal insmod virtio-rng.ko mean:0.001127s ±0.0ms (0.1%)
│ │ │ │ │
1.903939s: │ │ │ │ ▼
1.903939s: │ │ │ │ ▲ supermin: internal insmod virtio_console.ko mean:0.001509s ±0.4ms (0.1%)
│ │ │ │ │
1.905448s: │ │ │ │ ▼
1.905448s: │ │ │ │ ▲ supermin: internal insmod virtio_net.ko mean:0.001773s ±0.5ms (0.1%)
│ │ │ │ │
1.907221s: │ │ │ │ ▼
1.907221s: │ │ │ │ ▲ supermin: internal insmod virtio_scsi.ko mean:0.000543s ±0.5ms (0.0%)
1.907764s: │ │ │ │ ▼
1.907764s: │ │ │ │ ▲ supermin: internal insmod virtio_balloon.ko mean:0.000550s ±0.5ms (0.0%)
1.908314s: │ │ │ │ ▼
1.908314s: │ │ │ │ ▲ supermin: internal insmod virtio_input.ko mean:0.001099s ±0.0ms (0.0%)
│ │ │ │ │
1.909414s: │ │ │ │ ▼
1.909414s: │ │ │ │ ▲ supermin: internal insmod virtio_mmio.ko mean:0.001089s ±0.0ms (0.0%)
│ │ │ │ │
1.910503s: │ │ │ │ ▼
1.910503s: │ │ │ │ ▲ supermin: internal insmod virtio_pci.ko mean:0.030645s ±0.0ms (1.4%)
│ │ │ │ │
1.941148s: │ │ │ │ ▼
1.941148s: │ │ │ │ ▲ supermin: internal insmod crc-ccitt.ko mean:0.001691s ±0.0ms (0.1%)
│ │ │ │ │
1.942839s: │ │ │ │ ▼
1.942839s: │ │ │ │ ▲ supermin: internal insmod crc-itu-t.ko mean:0.000001s ±0.0ms (0.0%)
1.942840s: │ │ │ │ ▼
1.942840s: │ │ │ │ ▲ supermin: internal insmod crc8.ko mean:0.001430s ±0.3ms (0.1%)
│ │ │ │ │
1.944270s: │ │ │ │ ▼
1.944270s: │ │ │ │ ▲ supermin: internal insmod libcrc32c.ko mean:0.000834s ±0.8ms (0.0%)
1.945104s: │ │ │ │ ▼
│ │ │ │
1.949411s: │ │ │ ▼
1.949411s: │ │ │ ▲ ▲ /init mean:0.260724s ±4.4ms (11.7%) bash:overhead mean:0.006838s ±0.2ms (0.3%)
│ │ │ │ │
1.956249s: │ │ │ │ ▼
│ │ │ │
2.210135s: │ │ │ ▼
2.210135s: │ │ │ ▲ guestfsd mean:0.016110s ±0.3ms (0.7%)
│ │ │ │
2.218921s: │ │ │ │ ▲ shutdown mean:0.016509s ±2.5ms (0.7%)
│ │ │ │ │
2.226245s: │ │ │ ▼ │
│ │ │ │
2.235430s: ▼ ▼ ▼ ▼
next reply other threads:[~2016-03-19 20:31 UTC|newest]
Thread overview: 55+ messages / expand[flat|nested] mbox.gz Atom feed top
2016-03-19 20:31 Richard W.M. Jones [this message]
2016-03-21 7:58 ` [Qemu-devel] Why is SeaBIOS used with -kernel? Gerd Hoffmann
2016-03-21 8:37 ` Richard W.M. Jones
2016-03-21 9:40 ` Gerd Hoffmann
2016-03-31 9:21 ` Stefan Hajnoczi
2016-03-31 16:22 ` Kevin O'Connor
[not found] ` <20160331221039.GA32728@redhat.com>
2016-03-31 22:17 ` Richard W.M. Jones
2016-03-31 22:44 ` Kevin O'Connor
2016-04-01 7:55 ` Richard W.M. Jones
2016-04-01 8:03 ` Paolo Bonzini
2016-04-01 8:47 ` Richard W.M. Jones
2016-04-01 8:51 ` Paolo Bonzini
2016-04-01 8:57 ` Richard W.M. Jones
2016-04-01 9:05 ` Paolo Bonzini
2016-04-01 8:02 ` Richard W.M. Jones
2016-04-01 8:11 ` Paolo Bonzini
2016-04-01 8:14 ` Richard W.M. Jones
2016-04-01 8:24 ` Paolo Bonzini
2016-04-01 8:44 ` Richard W.M. Jones
2016-04-01 8:47 ` Paolo Bonzini
2016-04-01 8:49 ` Vasiliy Tolstov
2016-04-01 9:16 ` Dr. David Alan Gilbert
2016-04-01 9:18 ` Gerd Hoffmann
2016-04-01 10:17 ` Richard W.M. Jones
2016-04-01 11:07 ` Gerd Hoffmann
2016-04-01 11:11 ` Richard W.M. Jones
2016-04-01 11:20 ` Richard W.M. Jones
2016-04-01 11:21 ` Paolo Bonzini
2016-04-01 11:26 ` Richard W.M. Jones
2016-04-05 4:38 ` Kevin Wolf
2016-04-05 8:04 ` Richard W.M. Jones
2016-04-05 8:11 ` Kevin Wolf
2016-04-05 9:19 ` Richard W.M. Jones
2016-04-05 9:26 ` Kevin Wolf
2016-04-01 11:32 ` Gerd Hoffmann
2016-04-01 11:49 ` Richard W.M. Jones
2016-04-01 15:35 ` Kevin O'Connor
2016-04-01 16:03 ` Paolo Bonzini
2016-04-01 18:41 ` Richard W.M. Jones
2016-04-01 18:59 ` Richard W.M. Jones
2016-04-01 19:04 ` Kevin O'Connor
2016-04-01 19:10 ` Richard W.M. Jones
2016-04-01 19:15 ` Richard W.M. Jones
2016-04-01 19:44 ` Kevin O'Connor
2016-04-01 20:25 ` Richard W.M. Jones
2016-04-01 20:05 ` Kevin O'Connor
2016-04-01 20:46 ` Richard W.M. Jones
2016-04-01 22:25 ` Kevin O'Connor
2016-04-02 7:51 ` Richard W.M. Jones
2016-04-02 5:30 ` Paolo Bonzini
2016-04-01 15:08 ` Kevin O'Connor
2016-04-01 14:58 ` Kevin O'Connor
2016-04-01 15:06 ` Richard W.M. Jones
2016-04-01 15:14 ` Kevin O'Connor
2016-04-01 8:19 ` Richard W.M. Jones
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20160319203124.GB19398@redhat.com \
--to=rjones@redhat.com \
--cc=qemu-devel@nongnu.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.