[Libguestfs] [PATCH v2 0/7] tests/qemu: Add program for tracing and analyzing boot times.
Richard W.M. Jones
rjones at redhat.com
Sun Mar 20 12:40:48 UTC 2016
Typical analysis from this program attached.
(The real output from the program has pretty colours ...)
Rich.
--
Richard Jones, Virtualization Group, Red Hat http://people.redhat.com/~rjones
Read my programming and virtualization blog: http://rwmj.wordpress.com
virt-df lists disk usage of guests without needing to install any
software inside the virtual machine. Supports Linux and Windows.
http://people.redhat.com/~rjones/virt-df/
-------------- next part --------------
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 2282816890 ns
pass 2: 461 events collected in 2266873397 ns
pass 0
number of events collected 461
elapsed time 2282816890 ns
#0: +147443 [trace] "launch"
#1: +151110 [trace] "version"
#2: +159516 [trace] "version = <struct guestfs_version = major: 1, minor: 33, release: 15, extra: , >"
#3: +161830 [trace] "get_backend"
#4: +163814 [trace] "get_backend = "direct""
#5: +164982 [library] "launch: program=boot-analysis"
#6: +165903 [library] "launch: version=1.33.15"
#7: +166831 [library] "launch: backend registered: unix"
#8: +167616 [library] "launch: backend registered: uml"
#9: +168287 [library] "launch: backend registered: libvirt"
#10: +168899 [library] "launch: backend registered: direct"
#11: +169474 [library] "launch: backend=direct"
#12: +170141 [library] "launch: tmpdir=/home/rjones/d/libguestfs/tmp/libguestfsDOucPz"
#13: +202457 [library] "launch: umask=0002"
#14: +203374 [library] "launch: euid=1000"
#15: +220156 [trace] "get_backend_setting "force_tcg""
#16: +224124 [trace] "get_backend_setting = NULL (error)"
#17: +230759 [trace] "get_cachedir"
#18: +232760 [trace] "get_cachedir = "/home/rjones/d/libguestfs/tmp""
#19: +246029 [library] "begin building supermin appliance"
#20: +246607 [library] "run supermin"
#21: +249927 [library] "command: run: /usr/bin/supermin"
#22: +250539 [library] "command: run: \ --build"
#23: +251007 [library] "command: run: \ --verbose"
#24: +251471 [library] "command: run: \ --if-newer"
#25: +252083 [library] "command: run: \ --lock /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#26: +252789 [library] "command: run: \ --copy-kernel"
#27: +253367 [library] "command: run: \ -f ext2"
#28: +253964 [library] "command: run: \ --host-cpu x86_64"
#29: +254460 [library] "command: run: \ /home/rjones/d/libguestfs/appliance/supermin.d"
#30: +255101 [library] "command: run: \ -o /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d"
#31: +8276383 [appliance] "supermin: version: 5.1.15"
#32: +8277112 [appliance] "supermin: rpm: detected RPM version 4.13"
#33: +8277641 [appliance] "supermin: package handler: fedora/rpm"
#34: +8277846 [appliance] "supermin: acquiring lock on /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#35: +8279912 [appliance] "supermin: if-newer: output does not need rebuilding"
#36: +10738829 [library] "finished building supermin appliance"
#37: +10759858 [library] "begin testing qemu features"
#38: +10762666 [library] "command: run: /usr/bin/qemu-kvm"
#39: +10763144 [library] "command: run: \ -display none"
#40: +10763467 [library] "command: run: \ -help"
#41: +109881029 [library] "command: run: /usr/bin/qemu-kvm"
#42: +109882585 [library] "command: run: \ -display none"
#43: +109883183 [library] "command: run: \ -version"
#44: +204787129 [library] "qemu version 2.5"
#45: +204791498 [library] "command: run: /usr/bin/qemu-kvm"
#46: +204792374 [library] "command: run: \ -display none"
#47: +204792999 [library] "command: run: \ -machine accel=kvm:tcg"
#48: +204793611 [library] "command: run: \ -device ?"
#49: +301752570 [trace] "get_sockdir"
#50: +301757996 [trace] "get_sockdir = "/run/user/1000""
#51: +302140236 [library] "finished testing qemu features"
#52: +302151821 [trace] "get_backend_setting "gdb""
#53: +302156417 [trace] "get_backend_setting = NULL (error)"
#54: +304046282 [appliance] "[00302ms] /usr/bin/qemu-kvm \"
#55: +304048563 [appliance] " -global virtio-blk-pci.scsi=off \"
#56: +304050283 [appliance] " -nodefconfig \"
#57: +304051966 [appliance] " -enable-fips \"
#58: +304053570 [appliance] " -nodefaults \"
#59: +304055288 [appliance] " -display none \"
#60: +304056989 [appliance] " -machine accel=kvm:tcg \"
#61: +304058405 [appliance] " -cpu host \"
#62: +304059751 [appliance] " -m 500 \"
#63: +304061194 [appliance] " -no-reboot \"
#64: +304062616 [appliance] " -rtc driftfix=slew \"
#65: +304064126 [appliance] " -no-hpet \"
#66: +304065683 [appliance] " -global kvm-pit.lost_tick_policy=discard \"
#67: +304067208 [appliance] " -kernel /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/kernel \"
#68: +304068865 [appliance] " -initrd /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/initrd \"
#69: +304070394 [appliance] " -device virtio-scsi-pci,id=scsi \"
#70: +304071970 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/libguestfsDOucPz/devnull1,cache=writeback,id=hd0,if=none \"
#71: +304073902 [appliance] " -device scsi-hd,drive=hd0 \"
#72: +304075535 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \"
#73: +304077200 [appliance] " -device scsi-hd,drive=appliance \"
#74: +304078741 [appliance] " -device virtio-serial-pci \"
#75: +304080228 [appliance] " -serial stdio \"
#76: +304081626 [appliance] " -device sga \"
#77: +304083208 [appliance] " -chardev socket,path=/run/user/1000/libguestfs0hEfxo/guestfsd.sock,id=channel0 \"
#78: +304084864 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \"
#79: +304086528 [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: +402033642 [appliance] "WARNING: Image format was not specified for '/home/rjones/d/libguestfs/tmp/libguestfsDOucPz/devnull1' and probing guessed raw."
#81: +402036909 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted."
#82: +402037921 [appliance] " Specify the 'raw' format explicitly to remove the restrictions."
#83: +468615858 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n"
#84: +737817509 [appliance] "Google, Inc."
#85: +737820124 [appliance] "Serial Graphics Adapter 06/19/15"
#86: +737822013 [appliance] "SGABIOS $Id: sgabios.S 8 2010-04-22 00:03:40Z nlaredo $ (mockbuild@) Fri Jun 19 00:52:18 UTC 2015"
#87: +737823798 [appliance] "Term: 80x24"
#88: +737825462 [appliance] "4 0"
#89: +737827075 [appliance] "\x1b[2J\x0dSeaBIOS (version 1.8.2-20150714_191134-)"
#90: +847527635 [appliance] "\x0dBooting from ROM..."
#91: +1498583245 [appliance] "\x0dProbing EDD (edd=off to disable)... ok"
#92: +1498588180 [appliance] "\x1b[2J[ 0.000000] Initializing cgroup subsys cpuset"
#93: +1578297560 [appliance] "[ 0.000000] Initializing cgroup subsys cpu"
#94: +1578299341 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct"
#95: +1578300235 [appliance] "[ 0.000000] Linux version 4.4.4-301.fc23.x86_64 (mockbuild at 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: +1579437002 [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: +1580589541 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256"
#98: +1581723903 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'"
#99: +1581725406 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'"
#100: +1582860145 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'"
#101: +1582861673 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format."
#102: +1583995644 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches."
#103: +1583997147 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:"
#104: +1583998041 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable"
#105: +1585148018 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved"
#106: +1585150003 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved"
#107: +1585151262 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3dffff] usable"
#108: +1586287942 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3e0000-0x000000001f3fffff] reserved"
#109: +1586289402 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved"
#110: +1587425993 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved"
#111: +1587427505 [appliance] "[ 0.000000] NX (Execute Disable) protection: active"
#112: +1587428376 [appliance] "[ 0.000000] SMBIOS 2.8 present."
#113: +1588572045 [appliance] "[ 0.000000] Hypervisor detected: KVM"
#114: +1588573562 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3e0 max_arch_pfn = 0x400000000"
#115: +1588574564 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT "
#116: +1589708009 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f64d0-0x000f64df] mapped at [ffff8800000f64d0]"
#117: +1589709512 [appliance] "[ 0.000000] Using GB pages for direct mapping"
#118: +1589710419 [appliance] "[ 0.000000] RAMDISK: [mem 0x1f38a000-0x1f3dffff]"
#119: +1590843717 [appliance] "[ 0.000000] No NUMA configuration found"
#120: +1590845202 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3dffff]"
#121: +1590846149 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f378000-0x1f389fff]"
#122: +1591982264 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00"
#123: +1591983698 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f368001, primary cpu clock"
#124: +1591984626 [appliance] "[ 0.000000] kvm-clock: using sched offset of 1128250597 cycles"
#125: +1593132165 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"
#126: +1593133666 [appliance] "[ 0.000000] Zone ranges:"
#127: +1593134573 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]"
#128: +1594269741 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3dffff]"
#129: +1594271152 [appliance] "[ 0.000000] Normal empty"
#130: +1594272092 [appliance] "[ 0.000000] Movable zone start for each node"
#131: +1594272912 [appliance] "[ 0.000000] Early memory node ranges"
#132: +1595408325 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]"
#133: +1595409782 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3dffff]"
#134: +1595410612 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3dffff]"
#135: +1596545387 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org"
#136: +1596546756 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4"
#137: +1597694902 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU"
#138: +1597696375 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 "
#139: +1597697225 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000"
#140: +1597697986 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)"
#141: +1597698779 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23"
#142: +1598836161 [appliance] "[ 0.000000] Processors: 1"
#143: +1598837499 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs"
#144: +1598838367 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]"
#145: +1599971258 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]"
#146: +1599972658 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]"
#147: +1599973462 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]"
#148: +1601108016 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices"
#149: +1601109374 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM"
#150: +1602226775 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns"
#151: +1602228326 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1"
#152: +1603364627 [appliance] "[ 0.000000] PERCPU: Embedded 34 pages/cpu @ffff88001f000000 s98712 r8192 d32360 u2097152"
#153: +1603365993 [appliance] "[ 0.000000] KVM setup async PF for cpu 0"
#154: +1603366924 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00d900"
#155: +1604502833 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125849"
#156: +1604504205 [appliance] "[ 0.000000] Policy zone: DMA32"
#157: +1604505090 [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: +1605639283 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)"
#159: +1606775674 [appliance] "[ 0.000000] Memory: 485620K/511480K available (7827K kernel code, 1307K rwdata, 3444K rodata, 1528K init, 1544K bss, 25860K reserved, 0K cma-reserved)"
#160: +1607910593 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1"
#161: +1607911967 [appliance] "[ 0.000000] Hierarchical RCU implementation."
#162: +1607912837 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64."
#163: +1609048767 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1."
#164: +1609050038 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1"
#165: +1609050748 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16"
#166: +1610184515 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs"
#167: +1610185688 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0."
#168: +1610186341 [appliance] "[ 0.000000] Console: colour *CGA 80x25"
#169: +1610186953 [appliance] "[ 0.000000] console [ttyS0] enabled"
#170: +1611295424 [appliance] "[ 0.000000] tsc: Detected 2593.994 MHz processor"
#171: +1611296569 [appliance] "[ 0.041879] Calibrating delay loop (skipped) preset value.. 5187.98 BogoMIPS (lpj=2593994)"
#172: +1611297270 [appliance] "[ 0.042446] pid_max: default: 32768 minimum: 301"
#173: +1612411168 [appliance] "[ 0.042785] Security Framework initialized"
#174: +1612411881 [appliance] "[ 0.043064] Yama: becoming mindful."
#175: +1612412502 [appliance] "[ 0.043310] SELinux: Disabled at boot."
#176: +1613549975 [appliance] "[ 0.043660] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)"
#177: +1613551223 [appliance] "[ 0.044209] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)"
#178: +1613551900 [appliance] "[ 0.044717] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#179: +1614691667 [appliance] "[ 0.045187] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#180: +1614692714 [appliance] "[ 0.045791] Initializing cgroup subsys io"
#181: +1615818691 [appliance] "[ 0.046090] Initializing cgroup subsys memory"
#182: +1615819663 [appliance] "[ 0.046542] Disabling memory control group subsystem"
#183: +1615820334 [appliance] "[ 0.046882] Initializing cgroup subsys devices"
#184: +1616951514 [appliance] "[ 0.047200] Initializing cgroup subsys freezer"
#185: +1616952672 [appliance] "[ 0.047508] Initializing cgroup subsys net_cls"
#186: +1616953297 [appliance] "[ 0.047813] Initializing cgroup subsys perf_event"
#187: +1616953925 [appliance] "[ 0.048127] Initializing cgroup subsys net_prio"
#188: +1618070496 [appliance] "[ 0.048454] Initializing cgroup subsys hugetlb"
#189: +1618071474 [appliance] "[ 0.048771] Initializing cgroup subsys pids"
#190: +1619897918 [appliance] "[ 0.050009] mce: CPU supports 10 MCE banks"
#191: +1619899131 [appliance] "[ 0.050329] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0"
#192: +1619899847 [appliance] "[ 0.050701] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0"
#193: +1629517447 [appliance] "[ 0.059636] Freeing SMP alternatives memory: 28K (ffffffff81ec6000 - ffffffff81ecd000)"
#194: +1632098688 [appliance] "[ 0.062221] ftrace: allocating 29522 entries in 116 pages"
#195: +1653005102 [appliance] "[ 0.083103] x2apic enabled"
#196: +1653006772 [appliance] "[ 0.083481] Switched APIC routing to physical x2apic."
#197: +1654452726 [appliance] "[ 0.084544] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1"
#198: +1654453949 [appliance] "[ 0.084976] smpboot: CPU0: Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz (family: 0x6, model: 0x3d, stepping: 0x4)"
#199: +1654454686 [appliance] "[ 0.085665] Performance Events: 16-deep LBR, Broadwell events, Intel PMU driver."
#200: +1655600907 [appliance] "[ 0.086233] ... version: 2"
#201: +1655601951 [appliance] "[ 0.086495] ... bit width: 48"
#202: +1655602559 [appliance] "[ 0.086760] ... generic registers: 4"
#203: +1656739318 [appliance] "[ 0.087051] ... value mask: 0000ffffffffffff"
#204: +1656740352 [appliance] "[ 0.087395] ... max period: 000000007fffffff"
#205: +1656741030 [appliance] "[ 0.087735] ... fixed-purpose events: 3"
#206: +1657857199 [appliance] "[ 0.088012] ... event mask: 000000070000000f"
#207: +1657858360 [appliance] "[ 0.088804] x86: Booted up 1 node, 1 CPUs"
#208: +1657859005 [appliance] "[ 0.089082] smpboot: Total of 1 processors activated (5187.98 BogoMIPS)"
#209: +1658968912 [appliance] "[ 0.089737] devtmpfs: initialized"
#210: +1661143181 [appliance] "[ 0.091227] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns"
#211: +1661144425 [appliance] "[ 0.091939] atomic64_test: passed for x86-64 platform with CX8 and with SSE"
#212: +1662267067 [appliance] "[ 0.092406] pinctrl core: initialized pinctrl subsystem"
#213: +1662268242 [appliance] "[ 0.092803] RTC time: 12:39:27, date: 03/20/16"
#214: +1662268884 [appliance] "[ 0.093180] NET: Registered protocol family 16"
#215: +1663470095 [appliance] "[ 0.093601] cpuidle: using governor menu"
#216: +1663471301 [appliance] "[ 0.094036] PCI: Using configuration type 1 for base access"
#217: +1665163081 [appliance] "[ 0.095252] ACPI: Interpreter disabled."
#218: +1665164225 [appliance] "[ 0.095577] vgaarb: loaded"
#219: +1665164858 [appliance] "[ 0.095821] SCSI subsystem initialized"
#220: +1665165491 [appliance] "[ 0.096105] usbcore: registered new interface driver usbfs"
#221: +1666292082 [appliance] "[ 0.096488] usbcore: registered new interface driver hub"
#222: +1666293201 [appliance] "[ 0.096843] usbcore: registered new device driver usb"
#223: +1666293788 [appliance] "[ 0.097223] PCI: Probing PCI hardware"
#224: +1666294623 [appliance] "[ 0.097494] PCI host bridge to bus 0000:00"
#225: +1667427793 [appliance] "[ 0.097774] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]"
#226: +1667428825 [appliance] "[ 0.098183] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]"
#227: +1667429389 [appliance] "[ 0.098649] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]"
#228: +1672874977 [appliance] "[ 0.102946] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]"
#229: +1672876700 [appliance] "[ 0.103444] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]"
#230: +1672877345 [appliance] "[ 0.103897] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]"
#231: +1673996446 [appliance] "[ 0.104380] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]"
#232: +1673998919 [appliance] "[ 0.105138] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI"
#233: +1675117175 [appliance] "[ 0.105628] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB"
#234: +1689577809 [appliance] "[ 0.119624] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]"
#235: +1689579265 [appliance] "[ 0.120193] NetLabel: Initializing"
#236: +1689579867 [appliance] "[ 0.120425] NetLabel: domain hash size = 128"
#237: +1689580286 [appliance] "[ 0.120719] NetLabel: protocols = UNLABELED CIPSOv4"
#238: +1690691686 [appliance] "[ 0.121077] NetLabel: unlabeled traffic allowed by default"
#239: +1693098593 [appliance] "[ 0.121543] clocksource: Switched to clocksource kvm-clock"
#240: +1697406909 [appliance] "[ 0.127480] pnp: PnP ACPI: disabled"
#241: +1697408565 [appliance] "[ 0.128509] NET: Registered protocol family 2"
#242: +1698538885 [appliance] "[ 0.128969] TCP established hash table entries: 4096 (order: 3, 32768 bytes)"
#243: +1698539725 [appliance] "[ 0.129444] TCP bind hash table entries: 4096 (order: 4, 65536 bytes)"
#244: +1699672141 [appliance] "[ 0.129898] TCP: Hash tables configured (established 4096 bind 4096)"
#245: +1699673095 [appliance] "[ 0.130482] UDP hash table entries: 256 (order: 1, 8192 bytes)"
#246: +1699673529 [appliance] "[ 0.130885] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)"
#247: +1700803965 [appliance] "[ 0.131335] NET: Registered protocol family 1"
#248: +1700804777 [appliance] "[ 0.131633] pci 0000:00:00.0: Limiting direct PCI/PCI transfers"
#249: +1700805227 [appliance] "[ 0.132041] pci 0000:00:01.0: PIIX3: Enabling Passive Release"
#250: +1701932232 [appliance] "[ 0.132433] pci 0000:00:01.0: Activating ISA DMA hang workarounds"
#251: +1701933316 [appliance] "[ 0.132906] Unpacking initramfs..."
#252: +1703265782 [appliance] "[ 0.133374] Freeing initrd memory: 344K (ffff88001f38a000 - ffff88001f3e0000)"
#253: +1703266861 [appliance] "[ 0.133960] platform rtc_cmos: registered platform RTC device (no PNP device found)"
#254: +1704648489 [appliance] "[ 0.134732] futex hash table entries: 256 (order: 2, 16384 bytes)"
#255: +1704649641 [appliance] "[ 0.135168] audit: initializing netlink subsys (disabled)"
#256: +1704650164 [appliance] "[ 0.135528] audit: type=2000 audit(1458477567.955:1): initialized"
#257: +1705772643 [appliance] "[ 0.136123] Initialise system trusted keyring"
#258: +1705773567 [appliance] "[ 0.136470] HugeTLB registered 1 GB page size, pre-allocated 0 pages"
#259: +1705774079 [appliance] "[ 0.136893] HugeTLB registered 2 MB page size, pre-allocated 0 pages"
#260: +1708096268 [appliance] "[ 0.138196] zbud: loaded"
#261: +1708097257 [appliance] "[ 0.138567] VFS: Disk quotas dquot_6.6.0"
#262: +1708097778 [appliance] "[ 0.138848] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"
#263: +1709446211 [appliance] "[ 0.139571] Key type big_key registered"
#264: +1711289017 [appliance] "[ 0.141364] NET: Registered protocol family 38"
#265: +1711289999 [appliance] "[ 0.141709] Key type asymmetric registered"
#266: +1711290489 [appliance] "[ 0.141981] Asymmetric key parser 'x509' registered"
#267: +1711290871 [appliance] "[ 0.142338] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)"
#268: +1712419415 [appliance] "[ 0.142885] io scheduler noop registered"
#269: +1712420298 [appliance] "[ 0.143146] io scheduler deadline registered"
#270: +1712420708 [appliance] "[ 0.143449] io scheduler cfq registered (default)"
#271: +1713541204 [appliance] "[ 0.143853] pci_hotplug: PCI Hot Plug PCI Core version: 0.5"
#272: +1713542138 [appliance] "[ 0.144236] pciehp: PCI Express Hot Plug Controller Driver version: 0.4"
#273: +1714628531 [appliance] "[ 0.144782] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled"
#274: +1737387483 [appliance] "[ 0.167535] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A"
#275: +1738628968 [appliance] "[ 0.168780] Non-volatile memory driver v1.3"
#276: +1738629686 [appliance] "[ 0.169085] Linux agpgart interface v0.103"
#277: +1739962259 [appliance] "[ 0.170096] scsi host0: ata_piix"
#278: +1739962826 [appliance] "[ 0.170375] scsi host1: ata_piix"
#279: +1739963237 [appliance] "[ 0.170627] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14"
#280: +1739963693 [appliance] "[ 0.171086] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15"
#281: +1741066353 [appliance] "[ 0.171733] libphy: Fixed MDIO Bus: probed"
#282: +1741066821 [appliance] "[ 0.172049] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"
#283: +1742209296 [appliance] "[ 0.172489] ehci-pci: EHCI PCI platform driver"
#284: +1742210765 [appliance] "[ 0.172800] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"
#285: +1742211439 [appliance] "[ 0.173226] ohci-pci: OHCI PCI platform driver"
#286: +1743321291 [appliance] "[ 0.173537] uhci_hcd: USB Universal Host Controller Interface driver"
#287: +1743322081 [appliance] "[ 0.174017] usbcore: registered new interface driver usbserial"
#288: +1743322477 [appliance] "[ 0.174415] usbcore: registered new interface driver usbserial_generic"
#289: +1744454836 [appliance] "[ 0.174868] usbserial: USB Serial support registered for generic"
#290: +1744455829 [appliance] "[ 0.175273] i8042: PNP: No PS/2 controller found. Probing ports directly."
#291: +1745585579 [appliance] "[ 0.176217] serio: i8042 KBD port at 0x60,0x64 irq 1"
#292: +1745586473 [appliance] "[ 0.176546] serio: i8042 AUX port at 0x60,0x64 irq 12"
#293: +1746703324 [appliance] "[ 0.177121] mousedev: PS/2 mouse device common for all mice"
#294: +1746704288 [appliance] "[ 0.177640] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0"
#295: +1747824370 [appliance] "[ 0.178608] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3"
#296: +1748944259 [appliance] "[ 0.179306] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2"
#297: +1748945151 [appliance] "[ 0.180037] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0"
#298: +1750052288 [appliance] "[ 0.180532] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram"
#299: +1750053284 [appliance] "[ 0.181005] device-mapper: uevent: version 1.0.3"
#300: +1751178878 [appliance] "[ 0.181417] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel at redhat.com"
#301: +1751179833 [appliance] "[ 0.182046] hidraw: raw HID events driver (C) Jiri Kosina"
#302: +1752325114 [appliance] "[ 0.182434] usbcore: registered new interface driver usbhid"
#303: +1752326687 [appliance] "[ 0.182807] usbhid: USB HID core driver"
#304: +1752327439 [appliance] "[ 0.183090] drop_monitor: Initializing network drop monitor service"
#305: +1753453323 [appliance] "[ 0.183577] ip_tables: (C) 2000-2006 Netfilter Core Team"
#306: +1753454256 [appliance] "[ 0.183975] Initializing XFRM netlink socket"
#307: +1753454692 [appliance] "[ 0.184376] NET: Registered protocol family 10"
#308: +1754717315 [appliance] "[ 0.184807] mip6: Mobile IPv6"
#309: +1754718316 [appliance] "[ 0.185034] NET: Registered protocol family 17"
#310: +1754718746 [appliance] "[ 0.185444] microcode: CPU0 sig=0x306d4, pf=0x1, revision=0x1"
#311: +1754719212 [appliance] "[ 0.185838] microcode: Microcode Update Driver: v2.01 <tigran at aivazian.fsnet.co.uk>, Peter Oruba"
#312: +1755847009 [appliance] "[ 0.186436] AVX2 version of gcm_enc/dec engaged."
#313: +1755847753 [appliance] "[ 0.186739] AES CTR mode by8 optimization enabled"
#314: +1773249630 [appliance] "[ 0.203347] registered taskstats version 1"
#315: +1773250815 [appliance] "[ 0.203698] Loading compiled-in X.509 certificates"
#316: +1774482151 [appliance] "[ 0.204584] Loaded X.509 cert 'Fedora kernel signing key: ff671496ff3f386a8ef2031bac2201b2edb4da2a'"
#317: +1774483051 [appliance] "[ 0.205212] zswap: loaded using pool lzo/zbud"
#318: +1774483581 [appliance] "[ 0.205637] Magic number: 8:887:683"
#319: +1775598297 [appliance] "[ 0.205967] rtc_cmos rtc_cmos: setting system clock to 2016-03-20 12:39:27 UTC (1458477567)"
#320: +1898461040 [appliance] "[ 0.328531] Freeing unused kernel memory: 1528K (ffffffff81d48000 - ffffffff81ec6000)"
#321: +1898462356 [appliance] "[ 0.329079] Write protecting the kernel read-only data: 12288k"
#322: +1898463099 [appliance] "[ 0.329570] Freeing unused kernel memory: 352K (ffff8800017a8000 - ffff880001800000)"
#323: +1901110890 [appliance] "[ 0.331207] Freeing unused kernel memory: 652K (ffff880001b5d000 - ffff880001c00000)"
#324: +1901111838 [appliance] "supermin: mounting /proc"
#325: +1901112236 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 dietlibc"
#326: +1901130485 [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: +1902275395 [appliance] "supermin: uptime: 0.26 0.14"
#328: +1903378005 [appliance] "supermin: mounting /sys"
#329: +1903379037 [appliance] "supermin: internal insmod crc32-pclmul.ko"
#330: +1904726374 [appliance] "supermin: internal insmod crc32c-intel.ko"
#331: +1904727226 [appliance] "supermin: internal insmod crct10dif-pclmul.ko"
#332: +1905827944 [appliance] "supermin: internal insmod crc32.ko"
#333: +1906988159 [appliance] "supermin: internal insmod virtio.ko"
#334: +1908702651 [appliance] "supermin: internal insmod virtio_ring.ko"
#335: +1908703455 [appliance] "supermin: internal insmod virtio_blk.ko"
#336: +1909856826 [appliance] "supermin: internal insmod virtio-rng.ko"
#337: +1910953800 [appliance] "supermin: internal insmod virtio_console.ko"
#338: +1912990126 [appliance] "supermin: internal insmod virtio_net.ko"
#339: +1914243041 [appliance] "supermin: internal insmod virtio_scsi.ko"
#340: +1914243801 [appliance] "supermin: internal insmod virtio_balloon.ko"
#341: +1915341054 [appliance] "supermin: internal insmod virtio_input.ko"
#342: +1916441706 [appliance] "supermin: internal insmod virtio_mmio.ko"
#343: +1917538134 [appliance] "supermin: internal insmod virtio_pci.ko"
#344: +1919545587 [appliance] "[ 0.349669] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10"
#345: +1919546869 [appliance] "[ 0.350184] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver"
#346: +1921092009 [appliance] "[ 0.351188] scsi host2: Virtio SCSI HBA"
#347: +1921092886 [appliance] "[ 0.351623] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11"
#348: +1921093192 [appliance] "[ 0.352120] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver"
#349: +1925134272 [appliance] "[ 0.355232] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#350: +1925135515 [appliance] "[ 0.355993] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#351: +1940829827 [appliance] "[ 0.370948] sd 2:0:0:0: Attached scsi generic sg0 type 0"
#352: +1940831113 [appliance] "[ 0.371443] sd 2:0:1:0: Attached scsi generic sg1 type 0"
#353: +1940831419 [appliance] "[ 0.371937] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)"
#354: +1941930911 [appliance] "[ 0.372451] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)"
#355: +1941931311 [appliance] "[ 0.373111] sd 2:0:0:0: [sda] Write Protect is off"
#356: +1943035999 [appliance] "[ 0.373474] sd 2:0:1:0: [sdb] Write Protect is off"
#357: +1943036376 [appliance] "[ 0.373838] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#358: +1944140306 [appliance] "[ 0.374472] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#359: +1945499684 [appliance] "[ 0.375498] Dev sda: unable to read RDB block 8"
#360: +1945500501 [appliance] "[ 0.375950] sda: unable to read partition table"
#361: +1945500827 [appliance] "[ 0.376275] sda: partition table beyond EOD, enabling native capacity"
#362: +1947105724 [appliance] "[ 0.377163] sd 2:0:1:0: [sdb] Attached SCSI disk"
#363: +1947106648 [appliance] "[ 0.377549] Dev sda: unable to read RDB block 8"
#364: +1947106891 [appliance] "[ 0.377858] sda: unable to read partition table"
#365: +1947107080 [appliance] "[ 0.378161] sda: partition table beyond EOD, truncated"
#366: +1948211773 [appliance] "[ 0.378787] sd 2:0:0:0: [sda] Attached SCSI disk"
#367: +1948212192 [appliance] "supermin: internal insmod crc-ccitt.ko"
#368: +1949926809 [appliance] "supermin: internal insmod crc-itu-t.ko"
#369: +1949927509 [appliance] "supermin: internal insmod crc8.ko"
#370: +1951675280 [appliance] "supermin: internal insmod libcrc32c.ko"
#371: +1951676420 [appliance] "supermin: picked /sys/block/sdb/dev as root device"
#372: +1952783002 [appliance] "supermin: creating /dev/root as block special 8:16"
#373: +1952783853 [appliance] "supermin: mounting new root on /root"
#374: +1953939205 [appliance] "[ 0.384085] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem"
#375: +1956529358 [appliance] "[ 0.386671] EXT4-fs (sdb): mounted filesystem without journal. Opts: "
#376: +1956530329 [appliance] "supermin: chroot"
#377: +1965185616 [appliance] "Starting /init script ..."
#378: +2070362644 [appliance] "[ 0.500469] random: systemd-tmpfile urandom read with 80 bits of entropy available"
#379: +2071744483 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m"
#380: +2073121930 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m"
#381: +2073122583 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m"
#382: +2073124850 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m"
#383: +2074260427 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m"
#384: +2074261044 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:33] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#385: +2075597550 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:37] Failed to replace specifiers: /var/log/journal/%m"
#386: +2075598068 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:38] Failed to replace specifiers: /var/log/journal/%m"
#387: +2075598298 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:39] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#388: +2076681425 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd"
#389: +2080189956 [appliance] "starting version 229"
#390: +2147808021 [appliance] "[ 0.577887] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9"
#391: +2147809300 [appliance] "[ 0.578383] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0"
#392: +2182141938 [appliance] "[ 0.612232] intel_rapl: no valid rapl domains found in package 0"
#393: +2207026507 [appliance] "[ 0.637126] input: PC Speaker as /devices/platform/pcspkr/input/input4"
#394: +2215064188 [appliance] "[ 0.645194] random: nonblocking pool is initialized"
#395: +2222206065 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline"
#396: +2222207598 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline"
#397: +2223845143 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline"
#398: +2223846028 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline"
#399: +2225312012 [appliance] "+ guestfs_boot_analysis=1"
#400: +2226468203 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline"
#401: +2226469028 [appliance] "+ eval"
#402: +2227631960 [appliance] "+ grep -sq selinux=1 /proc/cmdline"
#403: +2227632978 [appliance] "+ shopt -s nullglob"
#404: +2227633277 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#405: +2228763365 [appliance] "+ echo 300"
#406: +2228764136 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#407: +2228764332 [appliance] "+ echo 300"
#408: +2228764484 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#409: +2228764627 [appliance] "+ echo noop"
#410: +2228764776 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#411: +2229862714 [appliance] "+ echo noop"
#412: +2229864052 [appliance] "+ shopt -u nullglob"
#413: +2229864252 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host"
#414: +2232073306 [appliance] "+ ip link set dev lo up"
#415: +2232076200 [appliance] "+ test '' = 1"
#416: +2232076664 [appliance] "+ mdadm -As --auto=yes --run"
#417: +2236022535 [appliance] "mdadm: No arrays found in config file or automatically"
#418: +2236024820 [appliance] "+ modprobe dm_mod"
#419: +2237430363 [appliance] "+ lvmetad"
#420: +2240145280 [appliance] "+ lvm vgchange -aay --sysinit"
#421: +2243949022 [appliance] " Configuration setting "global/notify_dbus" unknown."
#422: +2243949990 [appliance] " lvmetad is not active yet, using direct activation during sysinit"
#423: +2246643479 [appliance] "+ ldmtool create all"
#424: +2250354120 [appliance] "["
#425: +2250355138 [appliance] "]"
#426: +2250355312 [appliance] "+ test 1 = 1"
#427: +2250355470 [appliance] "+ test 1 '!=' 1"
#428: +2250355698 [appliance] "+ test '' = 1"
#429: +2251491263 [appliance] "+ cmd=guestfsd"
#430: +2251492238 [appliance] "+ test x '!=' x"
#431: +2251492464 [appliance] "+ test 1 = 1"
#432: +2251492692 [appliance] "+ cmd='guestfsd --verbose'"
#433: +2251492940 [appliance] "+ test '' = 1"
#434: +2251493145 [appliance] "+ echo guestfsd --verbose"
#435: +2251493352 [appliance] "guestfsd --verbose"
#436: +2251493562 [appliance] "+ guestfsd --verbose"
#437: +2260135598 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'"
#438: +2260137117 [appliance] "udevadm --debug settle"
#439: +2262363111 [appliance] "calling: settle"
#440: +2262370721 [launch_done] "launch done callback"
#441: +2262372472 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG"
#442: +2262373500 [library] "appliance is up"
#443: +2262390731 [trace] "launch = 0"
#444: +2262391594 [trace] "close"
#445: +2262392583 [library] "closing guestfs handle 0x55eb2eb8c7a0 (state 2)"
#446: +2262394907 [trace] "internal_autosync"
#447: +2264992750 [appliance] "guestfsd: main_loop: new request, len 0x28"
#448: +2264993776 [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: +2264994271 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0"
#450: +2266161113 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0"
#451: +2266161500 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=97708k,mode=755 freq=0 passno=0"
#452: +2266161815 [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: +2269956659 [appliance] "fsync /dev/sda"
#454: +2276086959 [trace] "internal_autosync = 0"
#455: +2276088930 [library] "sending SIGTERM to process 21607"
#456: +2282816237 [close] "close callback"
#457: +2282822347 [library] "command: run: rm"
#458: +2282823277 [library] "command: run: \ -rf /home/rjones/d/libguestfs/tmp/libguestfsDOucPz"
#459: +2283992941 [library] "command: run: rm"
#460: +2283993663 [library] "command: run: \ -rf /run/user/1000/libguestfs0hEfxo"
pass 1
number of events collected 461
elapsed time 2266873397 ns
#0: +139401 [trace] "launch"
#1: +141774 [trace] "version"
#2: +146241 [trace] "version = <struct guestfs_version = major: 1, minor: 33, release: 15, extra: , >"
#3: +148391 [trace] "get_backend"
#4: +150880 [trace] "get_backend = "direct""
#5: +152228 [library] "launch: program=boot-analysis"
#6: +153435 [library] "launch: version=1.33.15"
#7: +154232 [library] "launch: backend registered: unix"
#8: +154899 [library] "launch: backend registered: uml"
#9: +155697 [library] "launch: backend registered: libvirt"
#10: +156482 [library] "launch: backend registered: direct"
#11: +157173 [library] "launch: backend=direct"
#12: +157990 [library] "launch: tmpdir=/home/rjones/d/libguestfs/tmp/libguestfsnmgtRi"
#13: +189043 [library] "launch: umask=0002"
#14: +190505 [library] "launch: euid=1000"
#15: +202732 [trace] "get_backend_setting "force_tcg""
#16: +207479 [trace] "get_backend_setting = NULL (error)"
#17: +216104 [trace] "get_cachedir"
#18: +218906 [trace] "get_cachedir = "/home/rjones/d/libguestfs/tmp""
#19: +234673 [library] "begin building supermin appliance"
#20: +235610 [library] "run supermin"
#21: +239688 [library] "command: run: /usr/bin/supermin"
#22: +240625 [library] "command: run: \ --build"
#23: +241421 [library] "command: run: \ --verbose"
#24: +242122 [library] "command: run: \ --if-newer"
#25: +243248 [library] "command: run: \ --lock /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#26: +244072 [library] "command: run: \ --copy-kernel"
#27: +244889 [library] "command: run: \ -f ext2"
#28: +245609 [library] "command: run: \ --host-cpu x86_64"
#29: +246354 [library] "command: run: \ /home/rjones/d/libguestfs/appliance/supermin.d"
#30: +247211 [library] "command: run: \ -o /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d"
#31: +8214105 [appliance] "supermin: version: 5.1.15"
#32: +8215068 [appliance] "supermin: rpm: detected RPM version 4.13"
#33: +8215670 [appliance] "supermin: package handler: fedora/rpm"
#34: +8215907 [appliance] "supermin: acquiring lock on /home/rjones/d/libguestfs/tmp/.guestfs-1000/lock"
#35: +8217975 [appliance] "supermin: if-newer: output does not need rebuilding"
#36: +10620441 [library] "finished building supermin appliance"
#37: +10638767 [library] "begin testing qemu features"
#38: +10643999 [library] "command: run: /usr/bin/qemu-kvm"
#39: +10644845 [library] "command: run: \ -display none"
#40: +10646602 [library] "command: run: \ -help"
#41: +106273872 [library] "command: run: /usr/bin/qemu-kvm"
#42: +106274897 [library] "command: run: \ -display none"
#43: +106275478 [library] "command: run: \ -version"
#44: +203774409 [library] "qemu version 2.5"
#45: +203777225 [library] "command: run: /usr/bin/qemu-kvm"
#46: +203778092 [library] "command: run: \ -display none"
#47: +203778683 [library] "command: run: \ -machine accel=kvm:tcg"
#48: +203779187 [library] "command: run: \ -device ?"
#49: +301367769 [trace] "get_sockdir"
#50: +301372861 [trace] "get_sockdir = "/run/user/1000""
#51: +301737015 [library] "finished testing qemu features"
#52: +301747584 [trace] "get_backend_setting "gdb""
#53: +301751916 [trace] "get_backend_setting = NULL (error)"
#54: +303384552 [appliance] "[00302ms] /usr/bin/qemu-kvm \"
#55: +303385945 [appliance] " -global virtio-blk-pci.scsi=off \"
#56: +303386283 [appliance] " -nodefconfig \"
#57: +303386773 [appliance] " -enable-fips \"
#58: +303387008 [appliance] " -nodefaults \"
#59: +303387257 [appliance] " -display none \"
#60: +303387509 [appliance] " -machine accel=kvm:tcg \"
#61: +303387766 [appliance] " -cpu host \"
#62: +303388004 [appliance] " -m 500 \"
#63: +303388334 [appliance] " -no-reboot \"
#64: +303388622 [appliance] " -rtc driftfix=slew \"
#65: +303388862 [appliance] " -no-hpet \"
#66: +303389154 [appliance] " -global kvm-pit.lost_tick_policy=discard \"
#67: +303389481 [appliance] " -kernel /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/kernel \"
#68: +303389873 [appliance] " -initrd /home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/initrd \"
#69: +303390133 [appliance] " -device virtio-scsi-pci,id=scsi \"
#70: +303390454 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/libguestfsnmgtRi/devnull1,cache=writeback,id=hd0,if=none \"
#71: +303390740 [appliance] " -device scsi-hd,drive=hd0 \"
#72: +303391054 [appliance] " -drive file=/home/rjones/d/libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \"
#73: +303391438 [appliance] " -device scsi-hd,drive=appliance \"
#74: +303391705 [appliance] " -device virtio-serial-pci \"
#75: +303391969 [appliance] " -serial stdio \"
#76: +303392174 [appliance] " -device sga \"
#77: +303392418 [appliance] " -chardev socket,path=/run/user/1000/libguestfsRJNA2d/guestfsd.sock,id=channel0 \"
#78: +303392702 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \"
#79: +303393740 [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: +398564258 [appliance] "WARNING: Image format was not specified for '/home/rjones/d/libguestfs/tmp/libguestfsnmgtRi/devnull1' and probing guessed raw."
#81: +398565421 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted."
#82: +398565971 [appliance] " Specify the 'raw' format explicitly to remove the restrictions."
#83: +464682224 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n"
#84: +731815532 [appliance] "Google, Inc."
#85: +731816776 [appliance] "Serial Graphics Adapter 06/19/15"
#86: +731817499 [appliance] "SGABIOS $Id: sgabios.S 8 2010-04-22 00:03:40Z nlaredo $ (mockbuild@) Fri Jun 19 00:52:18 UTC 2015"
#87: +731818127 [appliance] "Term: 80x24"
#88: +731818568 [appliance] "4 0"
#89: +731818972 [appliance] "\x1b[2J\x0dSeaBIOS (version 1.8.2-20150714_191134-)"
#90: +841089745 [appliance] "\x0dBooting from ROM..."
#91: +1484308192 [appliance] "\x0dProbing EDD (edd=off to disable)... ok"
#92: +1484310651 [appliance] "\x1b[2J[ 0.000000] Initializing cgroup subsys cpuset"
#93: +1564645056 [appliance] "[ 0.000000] Initializing cgroup subsys cpu"
#94: +1564646172 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct"
#95: +1564646527 [appliance] "[ 0.000000] Linux version 4.4.4-301.fc23.x86_64 (mockbuild at 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: +1565793658 [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: +1568053603 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256"
#98: +1568055220 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'"
#99: +1568055920 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'"
#100: +1569195939 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'"
#101: +1569196790 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format."
#102: +1570339729 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches."
#103: +1570341239 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:"
#104: +1570341837 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable"
#105: +1571481410 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved"
#106: +1571482335 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved"
#107: +1572615889 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3dffff] usable"
#108: +1572617005 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3e0000-0x000000001f3fffff] reserved"
#109: +1572617396 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved"
#110: +1573751015 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved"
#111: +1573751871 [appliance] "[ 0.000000] NX (Execute Disable) protection: active"
#112: +1574885825 [appliance] "[ 0.000000] SMBIOS 2.8 present."
#113: +1574886641 [appliance] "[ 0.000000] Hypervisor detected: KVM"
#114: +1574887030 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3e0 max_arch_pfn = 0x400000000"
#115: +1574887450 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT "
#116: +1576020760 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f64d0-0x000f64df] mapped at [ffff8800000f64d0]"
#117: +1576021669 [appliance] "[ 0.000000] Using GB pages for direct mapping"
#118: +1576022098 [appliance] "[ 0.000000] RAMDISK: [mem 0x1f38a000-0x1f3dffff]"
#119: +1577157517 [appliance] "[ 0.000000] No NUMA configuration found"
#120: +1577158451 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3dffff]"
#121: +1577158901 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f378000-0x1f389fff]"
#122: +1578293304 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00"
#123: +1578294164 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f368001, primary cpu clock"
#124: +1578294585 [appliance] "[ 0.000000] kvm-clock: using sched offset of 1117368092 cycles"
#125: +1579428855 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns"
#126: +1579429744 [appliance] "[ 0.000000] Zone ranges:"
#127: +1580571321 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]"
#128: +1580572191 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3dffff]"
#129: +1580581295 [appliance] "[ 0.000000] Normal empty"
#130: +1580581767 [appliance] "[ 0.000000] Movable zone start for each node"
#131: +1581715560 [appliance] "[ 0.000000] Early memory node ranges"
#132: +1581716373 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]"
#133: +1581716796 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3dffff]"
#134: +1582850598 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3dffff]"
#135: +1582851451 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org"
#136: +1582851826 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4"
#137: +1583980321 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU"
#138: +1583981475 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 "
#139: +1583982103 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000"
#140: +1585119263 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)"
#141: +1585120164 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23"
#142: +1585120618 [appliance] "[ 0.000000] Processors: 1"
#143: +1585120984 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs"
#144: +1586254702 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]"
#145: +1586255585 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]"
#146: +1586255975 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]"
#147: +1587392642 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]"
#148: +1587393460 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices"
#149: +1588586224 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM"
#150: +1588587092 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns"
#151: +1588587939 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1"
#152: +1589725448 [appliance] "[ 0.000000] PERCPU: Embedded 34 pages/cpu @ffff88001f000000 s98712 r8192 d32360 u2097152"
#153: +1589726163 [appliance] "[ 0.000000] KVM setup async PF for cpu 0"
#154: +1590859380 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00d900"
#155: +1590860261 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125849"
#156: +1590860656 [appliance] "[ 0.000000] Policy zone: DMA32"
#157: +1590860968 [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: +1593141591 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)"
#159: +1593144920 [appliance] "[ 0.000000] Memory: 485620K/511480K available (7827K kernel code, 1307K rwdata, 3444K rodata, 1528K init, 1544K bss, 25860K reserved, 0K cma-reserved)"
#160: +1594279677 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1"
#161: +1594280495 [appliance] "[ 0.000000] Hierarchical RCU implementation."
#162: +1594280857 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64."
#163: +1595416032 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1."
#164: +1595416908 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1"
#165: +1596557474 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16"
#166: +1596558281 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs"
#167: +1596558679 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0."
#168: +1596558965 [appliance] "[ 0.000000] Console: colour *CGA 80x25"
#169: +1597686741 [appliance] "[ 0.000000] console [ttyS0] enabled"
#170: +1597687552 [appliance] "[ 0.000000] tsc: Detected 2593.994 MHz processor"
#171: +1597687893 [appliance] "[ 0.042322] Calibrating delay loop (skipped) preset value.. 5187.98 BogoMIPS (lpj=2593994)"
#172: +1598818246 [appliance] "[ 0.042899] pid_max: default: 32768 minimum: 301"
#173: +1598819117 [appliance] "[ 0.043247] Security Framework initialized"
#174: +1598819473 [appliance] "[ 0.043530] Yama: becoming mindful."
#175: +1598819751 [appliance] "[ 0.043776] SELinux: Disabled at boot."
#176: +1599948692 [appliance] "[ 0.044126] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)"
#177: +1599949504 [appliance] "[ 0.044667] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)"
#178: +1601083942 [appliance] "[ 0.045182] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#179: +1601103870 [appliance] "[ 0.045644] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)"
#180: +1602354592 [appliance] "[ 0.046257] Initializing cgroup subsys io"
#181: +1602355839 [appliance] "[ 0.046550] Initializing cgroup subsys memory"
#182: +1602356484 [appliance] "[ 0.047015] Disabling memory control group subsystem"
#183: +1602357037 [appliance] "[ 0.047366] Initializing cgroup subsys devices"
#184: +1603482878 [appliance] "[ 0.047676] Initializing cgroup subsys freezer"
#185: +1603483979 [appliance] "[ 0.048004] Initializing cgroup subsys net_cls"
#186: +1603484632 [appliance] "[ 0.048325] Initializing cgroup subsys perf_event"
#187: +1604608898 [appliance] "[ 0.048661] Initializing cgroup subsys net_prio"
#188: +1604610070 [appliance] "[ 0.049011] Initializing cgroup subsys hugetlb"
#189: +1604610703 [appliance] "[ 0.049318] Initializing cgroup subsys pids"
#190: +1606681477 [appliance] "[ 0.050568] mce: CPU supports 10 MCE banks"
#191: +1606682705 [appliance] "[ 0.050894] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0"
#192: +1606683312 [appliance] "[ 0.051266] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0"
#193: +1615740666 [appliance] "[ 0.059647] Freeing SMP alternatives memory: 28K (ffffffff81ec6000 - ffffffff81ecd000)"
#194: +1618329957 [appliance] "[ 0.062278] ftrace: allocating 29522 entries in 116 pages"
#195: +1639245067 [appliance] "[ 0.083108] x2apic enabled"
#196: +1639246590 [appliance] "[ 0.083504] Switched APIC routing to physical x2apic."
#197: +1640618314 [appliance] "[ 0.084557] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1"
#198: +1640619617 [appliance] "[ 0.085010] smpboot: CPU0: Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz (family: 0x6, model: 0x3d, stepping: 0x4)"
#199: +1641752086 [appliance] "[ 0.085737] Performance Events: 16-deep LBR, Broadwell events, Intel PMU driver."
#200: +1641753183 [appliance] "[ 0.086259] ... version: 2"
#201: +1641753868 [appliance] "[ 0.086520] ... bit width: 48"
#202: +1642887320 [appliance] "[ 0.086807] ... generic registers: 4"
#203: +1642888446 [appliance] "[ 0.087084] ... value mask: 0000ffffffffffff"
#204: +1642889053 [appliance] "[ 0.087426] ... max period: 000000007fffffff"
#205: +1642889644 [appliance] "[ 0.087785] ... fixed-purpose events: 3"
#206: +1643997597 [appliance] "[ 0.088067] ... event mask: 000000070000000f"
#207: +1643998680 [appliance] "[ 0.088876] x86: Booted up 1 node, 1 CPUs"
#208: +1645113532 [appliance] "[ 0.089164] smpboot: Total of 1 processors activated (5187.98 BogoMIPS)"
#209: +1645114628 [appliance] "[ 0.089820] devtmpfs: initialized"
#210: +1647435717 [appliance] "[ 0.091309] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns"
#211: +1647437208 [appliance] "[ 0.092033] atomic64_test: passed for x86-64 platform with CX8 and with SSE"
#212: +1648570136 [appliance] "[ 0.092509] pinctrl core: initialized pinctrl subsystem"
#213: +1648571251 [appliance] "[ 0.092902] RTC time: 12:39:30, date: 03/20/16"
#214: +1648571931 [appliance] "[ 0.093283] NET: Registered protocol family 16"
#215: +1649813088 [appliance] "[ 0.093715] cpuidle: using governor menu"
#216: +1649814266 [appliance] "[ 0.094161] PCI: Using configuration type 1 for base access"
#217: +1651492027 [appliance] "[ 0.095384] ACPI: Interpreter disabled."
#218: +1651493402 [appliance] "[ 0.095723] vgaarb: loaded"
#219: +1651494004 [appliance] "[ 0.095970] SCSI subsystem initialized"
#220: +1651494578 [appliance] "[ 0.096272] usbcore: registered new interface driver usbfs"
#221: +1652625942 [appliance] "[ 0.096667] usbcore: registered new interface driver hub"
#222: +1652627060 [appliance] "[ 0.097019] usbcore: registered new device driver usb"
#223: +1652627626 [appliance] "[ 0.097406] PCI: Probing PCI hardware"
#224: +1653790879 [appliance] "[ 0.097685] PCI host bridge to bus 0000:00"
#225: +1653792047 [appliance] "[ 0.097983] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]"
#226: +1653792749 [appliance] "[ 0.098385] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]"
#227: +1654897966 [appliance] "[ 0.098866] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]"
#228: +1659252834 [appliance] "[ 0.103113] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]"
#229: +1659254425 [appliance] "[ 0.103612] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]"
#230: +1659255065 [appliance] "[ 0.104041] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]"
#231: +1660375095 [appliance] "[ 0.104521] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]"
#232: +1660376209 [appliance] "[ 0.105277] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI"
#233: +1661501079 [appliance] "[ 0.105773] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB"
#234: +1676525754 [appliance] "[ 0.120383] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]"
#235: +1676527343 [appliance] "[ 0.120922] NetLabel: Initializing"
#236: +1676528014 [appliance] "[ 0.121139] NetLabel: domain hash size = 128"
#237: +1676528606 [appliance] "[ 0.121413] NetLabel: protocols = UNLABELED CIPSOv4"
#238: +1679736296 [appliance] "[ 0.121761] NetLabel: unlabeled traffic allowed by default"
#239: +1679737535 [appliance] "[ 0.124087] clocksource: Switched to clocksource kvm-clock"
#240: +1684459475 [appliance] "[ 0.128332] pnp: PnP ACPI: disabled"
#241: +1686180166 [appliance] "[ 0.130045] NET: Registered protocol family 2"
#242: +1686181360 [appliance] "[ 0.130556] TCP established hash table entries: 4096 (order: 3, 32768 bytes)"
#243: +1686182040 [appliance] "[ 0.131006] TCP bind hash table entries: 4096 (order: 4, 65536 bytes)"
#244: +1687323987 [appliance] "[ 0.131434] TCP: Hash tables configured (established 4096 bind 4096)"
#245: +1687325288 [appliance] "[ 0.131998] UDP hash table entries: 256 (order: 1, 8192 bytes)"
#246: +1688458606 [appliance] "[ 0.132380] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)"
#247: +1688459672 [appliance] "[ 0.132813] NET: Registered protocol family 1"
#248: +1688460315 [appliance] "[ 0.133098] pci 0000:00:00.0: Limiting direct PCI/PCI transfers"
#249: +1688460842 [appliance] "[ 0.133488] pci 0000:00:01.0: PIIX3: Enabling Passive Release"
#250: +1689589876 [appliance] "[ 0.133873] pci 0000:00:01.0: Activating ISA DMA hang workarounds"
#251: +1689590922 [appliance] "[ 0.134323] Unpacking initramfs..."
#252: +1690869934 [appliance] "[ 0.134757] Freeing initrd memory: 344K (ffff88001f38a000 - ffff88001f3e0000)"
#253: +1690871151 [appliance] "[ 0.135306] platform rtc_cmos: registered platform RTC device (no PNP device found)"
#254: +1692150258 [appliance] "[ 0.136028] futex hash table entries: 256 (order: 2, 16384 bytes)"
#255: +1692151431 [appliance] "[ 0.136456] audit: initializing netlink subsys (disabled)"
#256: +1692152068 [appliance] "[ 0.136797] audit: type=2000 audit(1458477570.228:1): initialized"
#257: +1693488247 [appliance] "[ 0.137368] Initialise system trusted keyring"
#258: +1693489376 [appliance] "[ 0.137721] HugeTLB registered 1 GB page size, pre-allocated 0 pages"
#259: +1693490036 [appliance] "[ 0.138114] HugeTLB registered 2 MB page size, pre-allocated 0 pages"
#260: +1695492419 [appliance] "[ 0.139386] zbud: loaded"
#261: +1695493520 [appliance] "[ 0.139736] VFS: Disk quotas dquot_6.6.0"
#262: +1695494120 [appliance] "[ 0.140037] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)"
#263: +1696830315 [appliance] "[ 0.140745] Key type big_key registered"
#264: +1698648419 [appliance] "[ 0.142517] NET: Registered protocol family 38"
#265: +1698649574 [appliance] "[ 0.142837] Key type asymmetric registered"
#266: +1698650142 [appliance] "[ 0.143101] Asymmetric key parser 'x509' registered"
#267: +1698650630 [appliance] "[ 0.143441] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)"
#268: +1699757284 [appliance] "[ 0.143960] io scheduler noop registered"
#269: +1699758351 [appliance] "[ 0.144218] io scheduler deadline registered"
#270: +1699758834 [appliance] "[ 0.144509] io scheduler cfq registered (default)"
#271: +1700871756 [appliance] "[ 0.144951] pci_hotplug: PCI Hot Plug PCI Core version: 0.5"
#272: +1700872825 [appliance] "[ 0.145504] pciehp: PCI Express Hot Plug Controller Driver version: 0.4"
#273: +1701981381 [appliance] "[ 0.146338] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled"
#274: +1725263660 [appliance] "[ 0.169120] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A"
#275: +1726732608 [appliance] "[ 0.170625] Non-volatile memory driver v1.3"
#276: +1726733819 [appliance] "[ 0.170934] Linux agpgart interface v0.103"
#277: +1728052309 [appliance] "[ 0.171928] scsi host0: ata_piix"
#278: +1728053464 [appliance] "[ 0.172211] scsi host1: ata_piix"
#279: +1728054048 [appliance] "[ 0.172434] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14"
#280: +1728054608 [appliance] "[ 0.172853] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15"
#281: +1729168429 [appliance] "[ 0.173476] libphy: Fixed MDIO Bus: probed"
#282: +1729169175 [appliance] "[ 0.173786] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver"
#283: +1729169683 [appliance] "[ 0.174200] ehci-pci: EHCI PCI platform driver"
#284: +1730303942 [appliance] "[ 0.174488] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver"
#285: +1730304877 [appliance] "[ 0.174872] ohci-pci: OHCI PCI platform driver"
#286: +1730305483 [appliance] "[ 0.175153] uhci_hcd: USB Universal Host Controller Interface driver"
#287: +1731440277 [appliance] "[ 0.175595] usbcore: registered new interface driver usbserial"
#288: +1731441370 [appliance] "[ 0.175952] usbcore: registered new interface driver usbserial_generic"
#289: +1731441947 [appliance] "[ 0.176356] usbserial: USB Serial support registered for generic"
#290: +1732558403 [appliance] "[ 0.176769] i8042: PNP: No PS/2 controller found. Probing ports directly."
#291: +1733773238 [appliance] "[ 0.177666] serio: i8042 KBD port at 0x60,0x64 irq 1"
#292: +1733775278 [appliance] "[ 0.178004] serio: i8042 AUX port at 0x60,0x64 irq 12"
#293: +1733776291 [appliance] "[ 0.178538] mousedev: PS/2 mouse device common for all mice"
#294: +1734866211 [appliance] "[ 0.179046] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0"
#295: +1736122554 [appliance] "[ 0.180003] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3"
#296: +1736123737 [appliance] "[ 0.180678] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2"
#297: +1737241349 [appliance] "[ 0.181383] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0"
#298: +1737242386 [appliance] "[ 0.181855] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram"
#299: +1738435495 [appliance] "[ 0.182323] device-mapper: uevent: version 1.0.3"
#300: +1738436644 [appliance] "[ 0.182715] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel at redhat.com"
#301: +1738437290 [appliance] "[ 0.183308] hidraw: raw HID events driver (C) Jiri Kosina"
#302: +1739584034 [appliance] "[ 0.183692] usbcore: registered new interface driver usbhid"
#303: +1739585080 [appliance] "[ 0.184033] usbhid: USB HID core driver"
#304: +1739585620 [appliance] "[ 0.184303] drop_monitor: Initializing network drop monitor service"
#305: +1740715371 [appliance] "[ 0.184760] ip_tables: (C) 2000-2006 Netfilter Core Team"
#306: +1740716398 [appliance] "[ 0.185124] Initializing XFRM netlink socket"
#307: +1740716930 [appliance] "[ 0.185483] NET: Registered protocol family 10"
#308: +1741838627 [appliance] "[ 0.185897] mip6: Mobile IPv6"
#309: +1741839672 [appliance] "[ 0.186093] NET: Registered protocol family 17"
#310: +1741840263 [appliance] "[ 0.186484] microcode: CPU0 sig=0x306d4, pf=0x1, revision=0x1"
#311: +1741840890 [appliance] "[ 0.186862] microcode: Microcode Update Driver: v2.01 <tigran at aivazian.fsnet.co.uk>, Peter Oruba"
#312: +1742977245 [appliance] "[ 0.187424] AVX2 version of gcm_enc/dec engaged."
#313: +1742978146 [appliance] "[ 0.187711] AES CTR mode by8 optimization enabled"
#314: +1761190772 [appliance] "[ 0.205062] registered taskstats version 1"
#315: +1761192139 [appliance] "[ 0.205385] Loading compiled-in X.509 certificates"
#316: +1762375083 [appliance] "[ 0.206244] Loaded X.509 cert 'Fedora kernel signing key: ff671496ff3f386a8ef2031bac2201b2edb4da2a'"
#317: +1762376206 [appliance] "[ 0.206852] zswap: loaded using pool lzo/zbud"
#318: +1762376854 [appliance] "[ 0.207256] Magic number: 8:887:683"
#319: +1763466629 [appliance] "[ 0.207568] rtc_cmos rtc_cmos: setting system clock to 2016-03-20 12:39:30 UTC (1458477570)"
#320: +1886127448 [appliance] "[ 0.330021] Freeing unused kernel memory: 1528K (ffffffff81d48000 - ffffffff81ec6000)"
#321: +1886129424 [appliance] "[ 0.330562] Write protecting the kernel read-only data: 12288k"
#322: +1886132750 [appliance] "[ 0.331080] Freeing unused kernel memory: 352K (ffff8800017a8000 - ffff880001800000)"
#323: +1888843733 [appliance] "[ 0.332742] Freeing unused kernel memory: 652K (ffff880001b5d000 - ffff880001c00000)"
#324: +1888844654 [appliance] "supermin: mounting /proc"
#325: +1888845046 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 dietlibc"
#326: +1890013809 [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: +1890014781 [appliance] "supermin: uptime: 0.27 0.14"
#328: +1891127695 [appliance] "supermin: mounting /sys"
#329: +1891128224 [appliance] "supermin: internal insmod crc32-pclmul.ko"
#330: +1892467473 [appliance] "supermin: internal insmod crc32c-intel.ko"
#331: +1892468289 [appliance] "supermin: internal insmod crct10dif-pclmul.ko"
#332: +1893570041 [appliance] "supermin: internal insmod crc32.ko"
#333: +1894659309 [appliance] "supermin: internal insmod virtio.ko"
#334: +1896422680 [appliance] "supermin: internal insmod virtio_ring.ko"
#335: +1896423390 [appliance] "supermin: internal insmod virtio_blk.ko"
#336: +1897501521 [appliance] "supermin: internal insmod virtio-rng.ko"
#337: +1898629654 [appliance] "supermin: internal insmod virtio_console.ko"
#338: +1900657612 [appliance] "supermin: internal insmod virtio_net.ko"
#339: +1901920188 [appliance] "supermin: internal insmod virtio_scsi.ko"
#340: +1903044166 [appliance] "supermin: internal insmod virtio_balloon.ko"
#341: +1903045442 [appliance] "supermin: internal insmod virtio_input.ko"
#342: +1904128275 [appliance] "supermin: internal insmod virtio_mmio.ko"
#343: +1905209093 [appliance] "supermin: internal insmod virtio_pci.ko"
#344: +1906282571 [appliance] "[ 0.351153] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10"
#345: +1907391885 [appliance] "[ 0.351667] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver"
#346: +1908770046 [appliance] "[ 0.352690] scsi host2: Virtio SCSI HBA"
#347: +1908771021 [appliance] "[ 0.353102] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11"
#348: +1908771444 [appliance] "[ 0.353598] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver"
#349: +1912827625 [appliance] "[ 0.356731] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#350: +1912829131 [appliance] "[ 0.357470] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5"
#351: +1931634509 [appliance] "[ 0.375493] sd 2:0:0:0: Attached scsi generic sg0 type 0"
#352: +1931635875 [appliance] "[ 0.376027] sd 2:0:1:0: Attached scsi generic sg1 type 0"
#353: +1931636107 [appliance] "[ 0.376556] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)"
#354: +1932757666 [appliance] "[ 0.377143] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)"
#355: +1934002572 [appliance] "[ 0.377865] sd 2:0:0:0: [sda] Write Protect is off"
#356: +1934003696 [appliance] "[ 0.378248] sd 2:0:1:0: [sdb] Write Protect is off"
#357: +1934003952 [appliance] "[ 0.378657] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#358: +1935128289 [appliance] "[ 0.379302] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA"
#359: +1936911379 [appliance] "[ 0.380705] Dev sda: unable to read RDB block 8"
#360: +1936912327 [appliance] "[ 0.381140] sda: unable to read partition table"
#361: +1936912566 [appliance] "[ 0.381490] sda: partition table beyond EOD, enabling native capacity"
#362: +1938500321 [appliance] "[ 0.382389] sd 2:0:1:0: [sdb] Attached SCSI disk"
#363: +1938501116 [appliance] "[ 0.382900] Dev sda: unable to read RDB block 8"
#364: +1938501336 [appliance] "[ 0.383215] sda: unable to read partition table"
#365: +1938501487 [appliance] "[ 0.383532] sda: partition table beyond EOD, truncated"
#366: +1939611728 [appliance] "[ 0.384237] sd 2:0:0:0: [sda] Attached SCSI disk"
#367: +1939612220 [appliance] "supermin: internal insmod crc-ccitt.ko"
#368: +1940714392 [appliance] "supermin: internal insmod crc-itu-t.ko"
#369: +1941821487 [appliance] "supermin: internal insmod crc8.ko"
#370: +1943365168 [appliance] "supermin: internal insmod libcrc32c.ko"
#371: +1943365983 [appliance] "supermin: picked /sys/block/sdb/dev as root device"
#372: +1944460610 [appliance] "supermin: creating /dev/root as block special 8:16"
#373: +1944461337 [appliance] "supermin: mounting new root on /root"
#374: +1944461511 [appliance] "[ 0.389441] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem"
#375: +1948265619 [appliance] "[ 0.392188] EXT4-fs (sdb): mounted filesystem without journal. Opts: "
#376: +1948266732 [appliance] "supermin: chroot"
#377: +1956567229 [appliance] "Starting /init script ..."
#378: +2064643002 [appliance] "[ 0.508528] random: systemd-tmpfile urandom read with 79 bits of entropy available"
#379: +2065944843 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m"
#380: +2067292216 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m"
#381: +2067293412 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m"
#382: +2067293710 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m"
#383: +2068440681 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m"
#384: +2068441058 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:33] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#385: +2069945670 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:37] Failed to replace specifiers: /var/log/journal/%m"
#386: +2069946507 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:38] Failed to replace specifiers: /var/log/journal/%m"
#387: +2069946791 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:39] Failed to replace specifiers: /var/log/journal/%m/system.journal"
#388: +2072200550 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd"
#389: +2074745745 [appliance] "starting version 229"
#390: +2166190858 [appliance] "[ 0.610068] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9"
#391: +2166192150 [appliance] "[ 0.610752] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0"
#392: +2190375042 [appliance] "[ 0.634255] input: PC Speaker as /devices/platform/pcspkr/input/input4"
#393: +2197211627 [appliance] "[ 0.641119] random: nonblocking pool is initialized"
#394: +2201263496 [appliance] "[ 0.645144] intel_rapl: no valid rapl domains found in package 0"
#395: +2210122223 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline"
#396: +2210123413 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline"
#397: +2211676758 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline"
#398: +2211677608 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline"
#399: +2214179490 [appliance] "+ guestfs_boot_analysis=1"
#400: +2214180419 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline"
#401: +2215360930 [appliance] "+ eval"
#402: +2215361784 [appliance] "+ grep -sq selinux=1 /proc/cmdline"
#403: +2215362026 [appliance] "+ shopt -s nullglob"
#404: +2215362185 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#405: +2216488450 [appliance] "+ echo 300"
#406: +2216488833 [appliance] "+ for f in '/sys/block/sd*/device/timeout'"
#407: +2216488970 [appliance] "+ echo 300"
#408: +2216489123 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#409: +2216489257 [appliance] "+ echo noop"
#410: +2217672460 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'"
#411: +2217674626 [appliance] "+ echo noop"
#412: +2217674953 [appliance] "+ shopt -u nullglob"
#413: +2217675279 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host"
#414: +2220033292 [appliance] "+ ip link set dev lo up"
#415: +2220034517 [appliance] "+ test '' = 1"
#416: +2220034797 [appliance] "+ mdadm -As --auto=yes --run"
#417: +2223956603 [appliance] "mdadm: No arrays found in config file or automatically"
#418: +2223957984 [appliance] "+ modprobe dm_mod"
#419: +2225298741 [appliance] "+ lvmetad"
#420: +2227762913 [appliance] "+ lvm vgchange -aay --sysinit"
#421: +2231333146 [appliance] " Configuration setting "global/notify_dbus" unknown."
#422: +2231334173 [appliance] " lvmetad is not active yet, using direct activation during sysinit"
#423: +2234022854 [appliance] "+ ldmtool create all"
#424: +2238833631 [appliance] "["
#425: +2238834839 [appliance] "]"
#426: +2238834990 [appliance] "+ test 1 = 1"
#427: +2238835145 [appliance] "+ test 1 '!=' 1"
#428: +2238835324 [appliance] "+ test '' = 1"
#429: +2240017320 [appliance] "+ cmd=guestfsd"
#430: +2240018150 [appliance] "+ test x '!=' x"
#431: +2240018398 [appliance] "+ test 1 = 1"
#432: +2240018533 [appliance] "+ cmd='guestfsd --verbose'"
#433: +2240018686 [appliance] "+ test '' = 1"
#434: +2240018827 [appliance] "+ echo guestfsd --verbose"
#435: +2240018953 [appliance] "guestfsd --verbose"
#436: +2240019070 [appliance] "+ guestfsd --verbose"
#437: +2248600573 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'"
#438: +2248601967 [appliance] "udevadm --debug settle"
#439: +2250839221 [appliance] "calling: settle"
#440: +2250847987 [launch_done] "launch done callback"
#441: +2250850513 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG"
#442: +2250852032 [library] "appliance is up"
#443: +2250877067 [trace] "launch = 0"
#444: +2250878155 [trace] "close"
#445: +2250879672 [library] "closing guestfs handle 0x55eb2eb8c7a0 (state 2)"
#446: +2250883093 [trace] "internal_autosync"
#447: +2253681120 [appliance] "guestfsd: main_loop: new request, len 0x28"
#448: +2253681925 [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: +2253682315 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0"
#450: +2254851718 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0"
#451: +2254852079 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=97708k,mode=755 freq=0 passno=0"
#452: +2255974417 [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: +2258852466 [appliance] "fsync /dev/sda"
#454: +2259948899 [trace] "internal_autosync = 0"
#455: +2259950967 [library] "sending SIGTERM to process 21627"
#456: +2266872725 [close] "close callback"
#457: +2266880057 [library] "command: run: rm"
#458: +2266881759 [library] "command: run: \ -rf /home/rjones/d/libguestfs/tmp/libguestfsnmgtRi"
#459: +2268445016 [library] "command: run: rm"
#460: +2268446292 [library] "command: run: \ -rf /run/user/1000/libguestfsRJNA2d"
Analyzing the results ...
activity 0:
name = run
start - end = 0.0 - 2274701058.0
mean elapsed = 2274701059.0
variance = 63484801030225.0
s.d = 7967735.0
percent = 100.0
activity 1:
name = supermin:build
start - end = 96929.0 - 10536212.0
mean elapsed = 10439284.0
variance = 2863962256.0
s.d = 53516.0
percent = 0.5
activity 2:
name = qemu:feature-detect
start - end = 10555890.5 - 301795202.5
mean elapsed = 291239313.0
variance = 19899334225.0
s.d = 141065.0
percent = 12.8
activity 3:
name = qemu
start - end = 303574861.0 - 2274701058.0
mean elapsed = 1971126198.0
variance = 58365871739536.0
s.d = 7639756.0
percent = 86.7
activity 4:
name = qemu:overhead
start - end = 303574861.0 - 466505618.0
mean elapsed = 162930758.0
variance = 2672626623489.0
s.d = 1634817.0
percent = 7.2
activity 5:
name = bios:overhead
start - end = 466505619.0 - 1571329958.0
mean elapsed = 1104824340.0
variance = 23619959641369.0
s.d = 4860037.0
percent = 48.6
activity 6:
name = sgabios
start - end = 466505619.0 - 734679600.5
mean elapsed = 268173982.5
variance = 1075855407990.2
s.d = 1037234.5
percent = 11.8
activity 7:
name = seabios
start - end = 734679601.5 - 1571329958.0
mean elapsed = 836650357.5
variance = 14613818954006.2
s.d = 3822802.5
percent = 36.8
activity 8:
name = kernel
start - end = 1571329959.0 - 2274701058.0
mean elapsed = 703371100.0
variance = 1310800589604.0
s.d = 1144902.0
percent = 30.9
activity 9:
name = kernel:overhead
start - end = 1571329959.0 - 1894835218.0
mean elapsed = 323505260.0
variance = 480608041081.0
s.d = 693259.0
percent = 14.2
activity 10:
name = supermin:mini-initrd
start - end = 1894835219.0 - 1952255107.5
mean elapsed = 57419889.5
variance = 4007189227412.2
s.d = 2001796.5
percent = 2.5
activity 11:
name = supermin: internal insmod crc32-pclmul.ko
start - end = 1897110208.5 - 1898453500.5
mean elapsed = 1343293.0
variance = 16353936.0
s.d = 4044.0
percent = 0.1
activity 12:
name = supermin: internal insmod crc32c-intel.ko
start - end = 1898453501.5 - 1898454334.5
mean elapsed = 834.0
variance = 324.0
s.d = 18.0
percent = 0.0
activity 13:
name = supermin: internal insmod crct10dif-pclmul.ko
start - end = 1898454335.5 - 1899555569.5
mean elapsed = 1101235.0
variance = 267289.0
s.d = 517.0
percent = 0.0
activity 14:
name = supermin: internal insmod crc32.ko
start - end = 1899555570.5 - 1900680311.0
mean elapsed = 1124741.5
variance = 1258369202.2
s.d = 35473.5
percent = 0.0
activity 15:
name = supermin: internal insmod virtio.ko
start - end = 1900680312.0 - 1902419242.5
mean elapsed = 1738931.5
variance = 597289160.2
s.d = 24439.5
percent = 0.1
activity 16:
name = supermin: internal insmod virtio_ring.ko
start - end = 1902419243.5 - 1902419999.5
mean elapsed = 757.0
variance = 2209.0
s.d = 47.0
percent = 0.0
activity 17:
name = supermin: internal insmod virtio_blk.ko
start - end = 1902420000.5 - 1903535750.5
mean elapsed = 1115751.0
variance = 1415264400.0
s.d = 37620.0
percent = 0.0
activity 18:
name = supermin: internal insmod virtio-rng.ko
start - end = 1903535751.5 - 1904648304.0
mean elapsed = 1112553.5
variance = 242720820.2
s.d = 15579.5
percent = 0.0
activity 19:
name = supermin: internal insmod virtio_console.ko
start - end = 1904648305.0 - 1906680446.0
mean elapsed = 2032142.0
variance = 17505856.0
s.d = 4184.0
percent = 0.1
activity 20:
name = supermin: internal insmod virtio_net.ko
start - end = 1906680447.0 - 1907938191.5
mean elapsed = 1257745.5
variance = 23333730.2
s.d = 4830.5
percent = 0.1
activity 21:
name = supermin: internal insmod virtio_scsi.ko
start - end = 1907938192.5 - 1908500560.5
mean elapsed = 562369.0
variance = 315404668881.0
s.d = 561609.0
percent = 0.0
activity 22:
name = supermin: internal insmod virtio_balloon.ko
start - end = 1908500561.5 - 1909049825.0
mean elapsed = 549264.5
variance = 300291396132.2
s.d = 547988.5
percent = 0.0
activity 23:
name = supermin: internal insmod virtio_input.ko
start - end = 1909049826.0 - 1910141567.5
mean elapsed = 1091742.5
variance = 79379190.2
s.d = 8909.5
percent = 0.0
activity 24:
name = supermin: internal insmod virtio_mmio.ko
start - end = 1910141568.5 - 1911230190.5
mean elapsed = 1088623.0
variance = 60918025.0
s.d = 7805.0
percent = 0.0
activity 25:
name = supermin: internal insmod virtio_pci.ko
start - end = 1911230191.5 - 1943768783.0
mean elapsed = 32538592.5
variance = 3476488901690.2
s.d = 1864534.5
percent = 1.4
activity 26:
name = supermin: internal insmod crc-ccitt.ko
start - end = 1943768784.0 - 1945177177.5
mean elapsed = 1408394.5
variance = 93772219506.2
s.d = 306222.5
percent = 0.1
activity 27:
name = supermin: internal insmod crc-itu-t.ko
start - end = 1945177178.5 - 1945731075.0
mean elapsed = 553897.5
variance = 306027474006.2
s.d = 553197.5
percent = 0.0
activity 28:
name = supermin: internal insmod crc8.ko
start - end = 1945731076.0 - 1947376801.0
mean elapsed = 1645726.0
variance = 10413182025.0
s.d = 102045.0
percent = 0.1
activity 29:
name = supermin: internal insmod libcrc32c.ko
start - end = 1947376802.0 - 1947377778.5
mean elapsed = 977.5
variance = 26406.2
s.d = 162.5
percent = 0.0
activity 30:
name = /init
start - end = 1952255108.5 - 2245612189.5
mean elapsed = 293357082.0
variance = 2576927088961.0
s.d = 1605281.0
percent = 12.9
activity 31:
name = bash:overhead
start - end = 1952255108.5 - 1960732999.5
mean elapsed = 8477892.0
variance = 31468986025.0
s.d = 177395.0
percent = 0.4
activity 32:
name = guestfsd
start - end = 2245612190.5 - 2264261139.5
mean elapsed = 18648950.0
variance = 34218710289.0
s.d = 184983.0
percent = 0.8
activity 33:
name = shutdown
start - end = 2256491452.5 - 2274701058.0
mean elapsed = 18209606.5
variance = 4906386696332.2
s.d = 2215036.5
percent = 0.8
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 at 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.274701s ?8.0ms (100.0%)
0.000097s: ? ? supermin:build mean:0.010439s ?0.1ms (0.5%)
? ?
0.010536s: ? ?
0.010556s: ? ? qemu:feature-detect mean:0.291239s ?0.1ms (12.8%)
? ?
0.301795s: ? ?
?
0.303575s: ? ? ? qemu mean:1.971126s ?7.6ms (86.7%) qemu:overhead mean:0.162931s ?1.6ms (7.2%)
? ? ?
0.466506s: ? ? ?
0.466506s: ? ? ? ? bios:overhead mean:1.104824s ?4.9ms (48.6%) sgabios mean:0.268174s ?1.0ms (11.8%)
? ? ? ?
0.734680s: ? ? ? ?
0.734680s: ? ? ? ? seabios mean:0.836650s ?3.8ms (36.8%)
? ? ? ?
1.571330s: ? ? ? ?
1.571330s: ? ? ? ? kernel mean:0.703371s ?1.1ms (30.9%) kernel:overhead mean:0.323505s ?0.7ms (14.2%)
? ? ? ?
1.894835s: ? ? ? ?
1.894835s: ? ? ? ? supermin:mini-initrd mean:0.057420s ?2.0ms (2.5%)
? ? ? ?
1.897110s: ? ? ? ? ? supermin: internal insmod crc32-pclmul.ko mean:0.001343s ?0.0ms (0.1%)
? ? ? ? ?
1.898454s: ? ? ? ? ?
1.898454s: ? ? ? ? ? supermin: internal insmod crc32c-intel.ko mean:0.000001s ?0.0ms (0.0%)
1.898454s: ? ? ? ? ?
1.898454s: ? ? ? ? ? supermin: internal insmod crct10dif-pclmul.ko mean:0.001101s ?0.0ms (0.0%)
? ? ? ? ?
1.899556s: ? ? ? ? ?
1.899556s: ? ? ? ? ? supermin: internal insmod crc32.ko mean:0.001125s ?0.0ms (0.0%)
? ? ? ? ?
1.900680s: ? ? ? ? ?
1.900680s: ? ? ? ? ? supermin: internal insmod virtio.ko mean:0.001739s ?0.0ms (0.1%)
? ? ? ? ?
1.902419s: ? ? ? ? ?
1.902419s: ? ? ? ? ? supermin: internal insmod virtio_ring.ko mean:0.000001s ?0.0ms (0.0%)
1.902420s: ? ? ? ? ?
1.902420s: ? ? ? ? ? supermin: internal insmod virtio_blk.ko mean:0.001116s ?0.0ms (0.0%)
? ? ? ? ?
1.903536s: ? ? ? ? ?
1.903536s: ? ? ? ? ? supermin: internal insmod virtio-rng.ko mean:0.001113s ?0.0ms (0.0%)
? ? ? ? ?
1.904648s: ? ? ? ? ?
1.904648s: ? ? ? ? ? supermin: internal insmod virtio_console.ko mean:0.002032s ?0.0ms (0.1%)
? ? ? ? ?
1.906680s: ? ? ? ? ?
1.906680s: ? ? ? ? ? supermin: internal insmod virtio_net.ko mean:0.001258s ?0.0ms (0.1%)
? ? ? ? ?
1.907938s: ? ? ? ? ?
1.907938s: ? ? ? ? ? supermin: internal insmod virtio_scsi.ko mean:0.000562s ?0.6ms (0.0%)
1.908501s: ? ? ? ? ?
1.908501s: ? ? ? ? ? supermin: internal insmod virtio_balloon.ko mean:0.000549s ?0.5ms (0.0%)
1.909050s: ? ? ? ? ?
1.909050s: ? ? ? ? ? supermin: internal insmod virtio_input.ko mean:0.001092s ?0.0ms (0.0%)
? ? ? ? ?
1.910142s: ? ? ? ? ?
1.910142s: ? ? ? ? ? supermin: internal insmod virtio_mmio.ko mean:0.001089s ?0.0ms (0.0%)
? ? ? ? ?
1.911230s: ? ? ? ? ?
1.911230s: ? ? ? ? ? supermin: internal insmod virtio_pci.ko mean:0.032539s ?1.9ms (1.4%)
? ? ? ? ?
1.943769s: ? ? ? ? ?
1.943769s: ? ? ? ? ? supermin: internal insmod crc-ccitt.ko mean:0.001408s ?0.3ms (0.1%)
? ? ? ? ?
1.945177s: ? ? ? ? ?
1.945177s: ? ? ? ? ? supermin: internal insmod crc-itu-t.ko mean:0.000554s ?0.6ms (0.0%)
1.945731s: ? ? ? ? ?
1.945731s: ? ? ? ? ? supermin: internal insmod crc8.ko mean:0.001646s ?0.1ms (0.1%)
? ? ? ? ?
1.947377s: ? ? ? ? ?
1.947377s: ? ? ? ? ? supermin: internal insmod libcrc32c.ko mean:0.000001s ?0.0ms (0.0%)
1.947378s: ? ? ? ? ?
? ? ? ?
1.952255s: ? ? ? ?
1.952255s: ? ? ? ? ? /init mean:0.293357s ?1.6ms (12.9%) bash:overhead mean:0.008478s ?0.2ms (0.4%)
? ? ? ? ?
1.960733s: ? ? ? ? ?
? ? ? ?
2.245612s: ? ? ? ?
2.245612s: ? ? ? ? guestfsd mean:0.018649s ?0.2ms (0.8%)
? ? ? ?
2.256491s: ? ? ? ? ? shutdown mean:0.018210s ?2.2ms (0.8%)
? ? ? ? ?
2.264261s: ? ? ? ? ?
? ? ? ?
2.274701s: ? ? ? ?
More information about the Libguestfs
mailing list