Warming up the libguestfs cache ... Running the tests in 2 passes ... pass 1: 486 events collected in 2474227320 ns pass 2: 486 events collected in 2445539058 ns pass 0 number of events collected 486 elapsed time 2474227320 ns #0: +176463 [trace] "launch" #1: +179231 [trace] "version" #2: +184590 [trace] "version = " #3: +187203 [trace] "get_backend" #4: +189053 [trace] "get_backend = "direct"" #5: +190818 [library] "launch: program=boot-analysis" #6: +191840 [library] "launch: version=1.33.15" #7: +192573 [library] "launch: backend registered: unix" #8: +193177 [library] "launch: backend registered: uml" #9: +193714 [library] "launch: backend registered: libvirt" #10: +194216 [library] "launch: backend registered: direct" #11: +195064 [library] "launch: backend=direct" #12: +195613 [library] "launch: tmpdir=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfs7dFFfg" #13: +237211 [library] "launch: umask=0002" #14: +238537 [library] "launch: euid=1000" #15: +255393 [trace] "get_backend_setting "force_tcg"" #16: +260870 [trace] "get_backend_setting = NULL (error)" #17: +268883 [trace] "get_cachedir" #18: +270964 [trace] "get_cachedir = "/home/kchamart/src/rwmj-fork-libguestfs/tmp"" #19: +286711 [library] "begin building supermin appliance" #20: +287236 [library] "run supermin" #21: +290486 [library] "command: run: /home/kchamart/src/supermin/src/supermin" #22: +291147 [library] "command: run: \ --build" #23: +291613 [library] "command: run: \ --verbose" #24: +292024 [library] "command: run: \ --if-newer" #25: +292613 [library] "command: run: \ --lock /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #26: +293426 [library] "command: run: \ --copy-kernel" #27: +293937 [library] "command: run: \ -f ext2" #28: +294596 [library] "command: run: \ --host-cpu x86_64" #29: +295087 [library] "command: run: \ /home/kchamart/src/rwmj-fork-libguestfs/appliance/supermin.d" #30: +295656 [library] "command: run: \ -o /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d" #31: +11918125 [appliance] "supermin: version: 5.1.15" #32: +11923195 [appliance] "supermin: rpm: detected RPM version 4.13" #33: +11923544 [appliance] "supermin: package handler: fedora/rpm" #34: +11923946 [appliance] "supermin: acquiring lock on /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #35: +11926645 [appliance] "supermin: if-newer: output does not need rebuilding" #36: +15109068 [library] "finished building supermin appliance" #37: +15136516 [library] "begin testing qemu features" #38: +15140381 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #39: +15141256 [library] "command: run: \ -display none" #40: +15141815 [library] "command: run: \ -help" #41: +103016917 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #42: +103019902 [library] "command: run: \ -display none" #43: +103021102 [library] "command: run: \ -version" #44: +191330486 [library] "qemu version 2.5" #45: +191336844 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #46: +191338246 [library] "command: run: \ -display none" #47: +191339260 [library] "command: run: \ -machine accel=kvm:tcg" #48: +191340150 [library] "command: run: \ -device ?" #49: +281068891 [trace] "get_sockdir" #50: +281076409 [trace] "get_sockdir = "/tmp"" #51: +281195242 [library] "finished testing qemu features" #52: +281213605 [trace] "get_backend_setting "gdb"" #53: +281221321 [trace] "get_backend_setting = NULL (error)" #54: +283394158 [appliance] "[00282ms] /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64 \" #55: +283399974 [appliance] " -global virtio-blk-pci.scsi=off \" #56: +283403624 [appliance] " -nodefconfig \" #57: +283406098 [appliance] " -enable-fips \" #58: +283408308 [appliance] " -nodefaults \" #59: +283410981 [appliance] " -display none \" #60: +283413471 [appliance] " -machine accel=kvm:tcg \" #61: +283415901 [appliance] " -cpu host \" #62: +283418204 [appliance] " -m 500 \" #63: +283420428 [appliance] " -no-reboot \" #64: +283422768 [appliance] " -rtc driftfix=slew \" #65: +283425178 [appliance] " -no-hpet \" #66: +283427671 [appliance] " -global kvm-pit.lost_tick_policy=discard \" #67: +283430208 [appliance] " -kernel /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/kernel \" #68: +283432991 [appliance] " -initrd /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/initrd \" #69: +283435514 [appliance] " -device virtio-scsi-pci,id=scsi \" #70: +283438131 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfs7dFFfg/devnull1,cache=writeback,id=hd0,if=none \" #71: +283440634 [appliance] " -device scsi-hd,drive=hd0 \" #72: +283443211 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \" #73: +283445804 [appliance] " -device scsi-hd,drive=appliance \" #74: +283448058 [appliance] " -device virtio-serial-pci \" #75: +283450281 [appliance] " -serial stdio \" #76: +283453251 [appliance] " -device sga \" #77: +283455644 [appliance] " -chardev socket,path=/tmp/libguestfsQeqi9r/guestfsd.sock,id=channel0 \" #78: +283458104 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \" #79: +283460751 [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=screen guestfs_boot_analysis=1'" #80: +379613690 [appliance] "WARNING: Image format was not specified for '/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfs7dFFfg/devnull1' and probing guessed raw." #81: +379619857 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted." #82: +379622380 [appliance] " Specify the 'raw' format explicitly to remove the restrictions." #83: +501741303 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n" #84: +504007171 [appliance] "Google, Inc." #85: +504009458 [appliance] "Serial Graphics Adapter 11/03/11" #86: +504010784 [appliance] "SGABIOS $Id$ (pbonzini@yakj.usersys.redhat.com) Thu Nov 3 13:33:51 UTC 2011" #87: +505122078 [appliance] "Term: 80x24" #88: +505124318 [appliance] "4 0" #89: +505125498 [appliance] "\x1b[2J\x0dSeaBIOS (version rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org)" #90: +574733275 [appliance] "\x0dBooting from ROM..." #91: +579252578 [appliance] "\x0dProbing EDD (edd=off to disable)... ok" #92: +579256208 [appliance] "\x1b[2J" #93: +744364290 [appliance] "[ 0.000000] Initializing cgroup subsys cpuset" #94: +744367504 [appliance] "[ 0.000000] Initializing cgroup subsys cpu" #95: +744368755 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct" #96: +745478301 [appliance] "[ 0.000000] Linux version 4.4.5-300.fc23.x86_64+debug (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Thu Mar 10 17:37:59 UTC 2016" #97: +747714045 [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=screen guestfs_boot_analysis=1" #98: +749942162 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256" #99: +751053157 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'" #100: +752171524 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'" #101: +753285131 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'" #102: +753287193 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format." #103: +754395303 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches." #104: +755504079 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:" #105: +756612599 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable" #106: +756614655 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved" #107: +757736101 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved" #108: +758846396 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3ddfff] usable" #109: +759954862 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3de000-0x000000001f3fffff] reserved" #110: +761065474 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved" #111: +761067513 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved" #112: +762176049 [appliance] "[ 0.000000] NX (Execute Disable) protection: active" #113: +763287138 [appliance] "[ 0.000000] SMBIOS 2.8 present." #114: +763289242 [appliance] "[ 0.000000] Hypervisor detected: KVM" #115: +764397816 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3de max_arch_pfn = 0x400000000" #116: +764399896 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT " #117: +765509003 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f6bd0-0x000f6bdf] mapped at [ffff8800000f6bd0]" #118: +766621565 [appliance] "[ 0.000000] Scanning 1 areas for low memory corruption" #119: +767738506 [appliance] "[ 0.000000] Using GB pages for direct mapping" #120: +767740581 [appliance] "[ 0.000000] RAMDISK: [mem 0x00ee3000-0x00ffffff]" #121: +768847262 [appliance] "[ 0.000000] No NUMA configuration found" #122: +768849305 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3ddfff]" #123: +769959211 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f3cb000-0x1f3ddfff]" #124: +771069821 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00" #125: +771071960 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f3bb001, primary cpu clock" #126: +772181562 [appliance] "[ 0.000000] kvm-clock: using sched offset of 224139771 cycles" #127: +773295071 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns" #128: +774411300 [appliance] "[ 0.000000] Zone ranges:" #129: +774413369 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]" #130: +775520410 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3ddfff]" #131: +776630878 [appliance] "[ 0.000000] Normal empty" #132: +776632932 [appliance] "[ 0.000000] Movable zone start for each node" #133: +777738931 [appliance] "[ 0.000000] Early memory node ranges" #134: +777741231 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]" #135: +778848392 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3ddfff]" #136: +778850400 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3ddfff]" #137: +779959384 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org" #138: +781071833 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4" #139: +782182113 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU" #140: +782184148 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 " #141: +783300641 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000" #142: +783302644 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)" #143: +783303762 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23" #144: +784411633 [appliance] "[ 0.000000] Processors: 1" #145: +785524618 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs" #146: +785526646 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]" #147: +786643727 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]" #148: +787751487 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]" #149: +787753510 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]" #150: +788871505 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices" #151: +789978565 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM" #152: +789980611 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns" #153: +792208938 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1" #154: +793320968 [appliance] "[ 0.000000] PERCPU: Embedded 483 pages/cpu @ffff88001f000000 s1937944 r8192 d32232 u2097152" #155: +794450626 [appliance] "[ 0.000000] KVM setup async PF for cpu 0" #156: +794452839 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00db40" #157: +795582719 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125562" #158: +795584952 [appliance] "[ 0.000000] Policy zone: DMA32" #159: +796703011 [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=screen guestfs_boot_analysis=1" #160: +798929194 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)" #161: +800038908 [appliance] "[ 0.000000] Memory: 463228K/511472K available (8747K kernel code, 1490K rwdata, 3660K rodata, 3536K init, 16580K bss, 48244K reserved, 0K cma-reserved)" #162: +801147569 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1" #163: +802256485 [appliance] "[ 0.000000] Running RCU self tests" #164: +803366096 [appliance] "[ 0.000000] Hierarchical RCU implementation." #165: +803367970 [appliance] "[ 0.000000] \x09RCU lockdep checking is enabled." #166: +804478790 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64." #167: +804480713 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1." #168: +805589744 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1" #169: +806711898 [appliance] "[ 0.000000] kmemleak: Kernel memory leak detector disabled" #170: +806713523 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16" #171: +807821646 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs" #172: +807823092 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0." #173: +808930652 [appliance] "[ 0.000000] Console: colour *CGA 80x25" #174: +808932464 [appliance] "[ 0.000000] console [ttyS0] enabled" #175: +810043109 [appliance] "[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar" #176: +811152966 [appliance] "[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8" #177: +811154745 [appliance] "[ 0.000000] ... MAX_LOCK_DEPTH: 48" #178: +812263968 [appliance] "[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191" #179: +812265678 [appliance] "[ 0.000000] ... CLASSHASH_SIZE: 4096" #180: +813373596 [appliance] "[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 32768" #181: +813375310 [appliance] "[ 0.000000] ... MAX_LOCKDEP_CHAINS: 65536" #182: +814485962 [appliance] "[ 0.000000] ... CHAINHASH_SIZE: 32768" #183: +814487665 [appliance] "[ 0.000000] memory used by lock dependency info: 8671 kB" #184: +815597910 [appliance] "[ 0.000000] per task-struct memory footprint: 2688 bytes" #185: +816709020 [appliance] "[ 0.000000] tsc: Detected 2099.998 MHz processor" #186: +817812742 [appliance] "[ 0.122675] Calibrating delay loop (skipped) preset value.. 4199.99 BogoMIPS (lpj=2099998)" #187: +818924754 [appliance] "[ 0.123784] pid_max: default: 32768 minimum: 301" #188: +818926510 [appliance] "[ 0.124501] Security Framework initialized" #189: +820042390 [appliance] "[ 0.125063] Yama: becoming mindful." #190: +820044113 [appliance] "[ 0.125561] SELinux: Disabled at boot." #191: +821153442 [appliance] "[ 0.126263] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)" #192: +822257174 [appliance] "[ 0.127356] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)" #193: +823365042 [appliance] "[ 0.128347] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)" #194: +824476301 [appliance] "[ 0.129242] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)" #195: +826631272 [appliance] "[ 0.131256] Initializing cgroup subsys io" #196: +826633232 [appliance] "[ 0.131859] Initializing cgroup subsys memory" #197: +827733101 [appliance] "[ 0.132751] Disabling memory control group subsystem" #198: +827734831 [appliance] "[ 0.133411] Initializing cgroup subsys devices" #199: +828840284 [appliance] "[ 0.134045] Initializing cgroup subsys freezer" #200: +829953892 [appliance] "[ 0.134674] Initializing cgroup subsys net_cls" #201: +829955604 [appliance] "[ 0.135268] Initializing cgroup subsys perf_event" #202: +831062146 [appliance] "[ 0.135927] Initializing cgroup subsys net_prio" #203: +831063853 [appliance] "[ 0.136538] Initializing cgroup subsys hugetlb" #204: +832168304 [appliance] "[ 0.137156] Initializing cgroup subsys pids" #205: +834055258 [appliance] "[ 0.138682] mce: CPU supports 10 MCE banks" #206: +834057256 [appliance] "[ 0.139304] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0" #207: +835166961 [appliance] "[ 0.140026] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0" #208: +851807507 [appliance] "[ 0.156436] Freeing SMP alternatives memory: 28K (ffffffff822ea000 - ffffffff822f1000)" #209: +857221286 [appliance] "[ 0.161863] ftrace: allocating 29768 entries in 117 pages" #210: +909397282 [appliance] "[ 0.214028] x2apic enabled" #211: +909399844 [appliance] "[ 0.214908] Switched APIC routing to physical x2apic." #212: +912619915 [appliance] "[ 0.217227] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1" #213: +912622479 [appliance] "[ 0.218271] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2620 v2 @ 2.10GHz (family: 0x6, model: 0x3e, stepping: 0x4)" #214: +914858489 [appliance] "[ 0.220040] Performance Events: 16-deep LBR, IvyBridge events, Intel PMU driver." #215: +915980439 [appliance] "[ 0.221511] ... version: 2" #216: +917094539 [appliance] "[ 0.222201] ... bit width: 48" #217: +918223798 [appliance] "[ 0.222886] ... generic registers: 4" #218: +918225236 [appliance] "[ 0.223570] ... value mask: 0000ffffffffffff" #219: +919326781 [appliance] "[ 0.224432] ... max period: 000000007fffffff" #220: +920432867 [appliance] "[ 0.225325] ... fixed-purpose events: 3" #221: +920434021 [appliance] "[ 0.225978] ... event mask: 000000070000000f" #222: +924139133 [appliance] "[ 0.228784] x86: Booted up 1 node, 1 CPUs" #223: +924140413 [appliance] "[ 0.229446] smpboot: Total of 1 processors activated (4199.99 BogoMIPS)" #224: +927468988 [appliance] "[ 0.232136] devtmpfs: initialized" #225: +932015589 [appliance] "[ 0.236659] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns" #226: +933111556 [appliance] "[ 0.238424] atomic64_test: passed for x86-64 platform with CX8 and with SSE" #227: +934204817 [appliance] "[ 0.239498] pinctrl core: initialized pinctrl subsystem" #228: +935299574 [appliance] "[ 0.240652] RTC time: 7:51:49, date: 03/22/16" #229: +936379169 [appliance] "[ 0.241859] NET: Registered protocol family 16" #230: +938701488 [appliance] "[ 0.243366] cpuidle: using governor menu" #231: +939880920 [appliance] "[ 0.244561] PCI: Using configuration type 1 for base access" #232: +941000771 [appliance] "[ 0.245668] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off" #233: +948960081 [appliance] "[ 0.253632] ACPI: Interpreter disabled." #234: +948961125 [appliance] "[ 0.254666] vgaarb: loaded" #235: +950055249 [appliance] "[ 0.255326] SCSI subsystem initialized" #236: +951430931 [appliance] "[ 0.256094] usbcore: registered new interface driver usbfs" #237: +951432097 [appliance] "[ 0.256866] usbcore: registered new interface driver hub" #238: +952518678 [appliance] "[ 0.257607] usbcore: registered new device driver usb" #239: +953880613 [appliance] "[ 0.258546] PCI: Probing PCI hardware" #240: +953881689 [appliance] "[ 0.259206] PCI host bridge to bus 0000:00" #241: +954984277 [appliance] "[ 0.259764] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]" #242: +954985318 [appliance] "[ 0.260569] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]" #243: +956089133 [appliance] "[ 0.261493] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]" #244: +969057556 [appliance] "[ 0.273731] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]" #245: +970953988 [appliance] "[ 0.276174] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]" #246: +972045597 [appliance] "[ 0.277026] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]" #247: +973142908 [appliance] "[ 0.277958] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]" #248: +974911930 [appliance] "[ 0.279582] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI" #249: +974912848 [appliance] "[ 0.280535] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB" #250: +1030734276 [appliance] "[ 0.335393] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]" #251: +1033901376 [appliance] "[ 0.338559] NetLabel: Initializing" #252: +1033902439 [appliance] "[ 0.339034] NetLabel: domain hash size = 128" #253: +1033902964 [appliance] "[ 0.339605] NetLabel: protocols = UNLABELED CIPSOv4" #254: +1035004968 [appliance] "[ 0.340318] NetLabel: unlabeled traffic allowed by default" #255: +1036104938 [appliance] "[ 0.341297] clocksource: Switched to clocksource kvm-clock" #256: +1078673923 [appliance] "[ 0.383235] pnp: PnP ACPI: disabled" #257: +1085624669 [appliance] "[ 0.390236] NET: Registered protocol family 2" #258: +1086899471 [appliance] "[ 0.391542] TCP established hash table entries: 4096 (order: 3, 32768 bytes)" #259: +1086901206 [appliance] "[ 0.392562] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)" #260: +1088006913 [appliance] "[ 0.393647] TCP: Hash tables configured (established 4096 bind 4096)" #261: +1089118400 [appliance] "[ 0.394694] UDP hash table entries: 256 (order: 3, 49152 bytes)" #262: +1090234306 [appliance] "[ 0.395558] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)" #263: +1091341728 [appliance] "[ 0.396610] NET: Registered protocol family 1" #264: +1092451177 [appliance] "[ 0.397212] pci 0000:00:00.0: Limiting direct PCI/PCI transfers" #265: +1092452609 [appliance] "[ 0.397982] pci 0000:00:01.0: PIIX3: Enabling Passive Release" #266: +1093560281 [appliance] "[ 0.398768] pci 0000:00:01.0: Activating ISA DMA hang workarounds" #267: +1094701330 [appliance] "[ 0.399918] Unpacking initramfs..." #268: +1098965209 [appliance] "[ 0.403570] Freeing initrd memory: 1140K (ffff880000ee3000 - ffff880001000000)" #269: +1118536860 [appliance] "[ 0.423096] DMA-API: preallocated 65536 debug entries" #270: +1118539010 [appliance] "[ 0.423838] DMA-API: debugging enabled by kernel config" #271: +1119644334 [appliance] "[ 0.424821] platform rtc_cmos: registered platform RTC device (no PNP device found)" #272: +1121870183 [appliance] "[ 0.426525] Scanning for low memory corruption every 60 seconds" #273: +1123881767 [appliance] "[ 0.428491] futex hash table entries: 256 (order: 3, 32768 bytes)" #274: +1123883507 [appliance] "[ 0.429366] audit: initializing netlink subsys (disabled)" #275: +1124988279 [appliance] "[ 0.430161] audit: type=2000 audit(1458633109.792:1): initialized" #276: +1126097388 [appliance] "[ 0.431177] cryptomgr_test (27) used greatest stack depth: 14040 bytes left" #277: +1128346570 [appliance] "[ 0.433001] Initialise system trusted keyring" #278: +1129478231 [appliance] "[ 0.434108] HugeTLB registered 1 GB page size, pre-allocated 0 pages" #279: +1129479879 [appliance] "[ 0.434957] HugeTLB registered 2 MB page size, pre-allocated 0 pages" #280: +1140099074 [appliance] "[ 0.444737] zbud: loaded" #281: +1141271673 [appliance] "[ 0.445911] VFS: Disk quotas dquot_6.6.0" #282: +1141273279 [appliance] "[ 0.446605] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)" #283: +1145211028 [appliance] "[ 0.449824] Key type big_key registered" #284: +1145212671 [appliance] "[ 0.450875] cryptomgr_test (35) used greatest stack depth: 13688 bytes left" #285: +1151252786 [appliance] "[ 0.455874] cryptomgr_test (53) used greatest stack depth: 13312 bytes left" #286: +1153802717 [appliance] "[ 0.458411] NET: Registered protocol family 38" #287: +1153804320 [appliance] "[ 0.459085] Key type asymmetric registered" #288: +1154901331 [appliance] "[ 0.459764] Asymmetric key parser 'x509' registered" #289: +1154902725 [appliance] "[ 0.460619] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)" #290: +1157122587 [appliance] "[ 0.461769] io scheduler noop registered" #291: +1157124240 [appliance] "[ 0.462324] io scheduler deadline registered" #292: +1158377494 [appliance] "[ 0.463042] io scheduler cfq registered (default)" #293: +1161654824 [appliance] "[ 0.466266] pci_hotplug: PCI Hot Plug PCI Core version: 0.5" #294: +1161656494 [appliance] "[ 0.467030] pciehp: PCI Express Hot Plug Controller Driver version: 0.4" #295: +1162750644 [appliance] "[ 0.468425] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled" #296: +1189357352 [appliance] "[ 0.493962] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A" #297: +1197148629 [appliance] "[ 0.501766] Non-volatile memory driver v1.3" #298: +1197150524 [appliance] "[ 0.502513] Linux agpgart interface v0.103" #299: +1201895848 [appliance] "[ 0.506513] scsi host0: ata_piix" #300: +1201897751 [appliance] "[ 0.507428] scsi host1: ata_piix" #301: +1203001340 [appliance] "[ 0.508042] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14" #302: +1204103697 [appliance] "[ 0.508939] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15" #303: +1206001967 [appliance] "[ 0.510629] libphy: Fixed MDIO Bus: probed" #304: +1206003603 [appliance] "[ 0.511406] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver" #305: +1207112028 [appliance] "[ 0.512285] ehci-pci: EHCI PCI platform driver" #306: +1208265911 [appliance] "[ 0.512916] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver" #307: +1208267604 [appliance] "[ 0.513743] ohci-pci: OHCI PCI platform driver" #308: +1209384229 [appliance] "[ 0.514376] uhci_hcd: USB Universal Host Controller Interface driver" #309: +1210487141 [appliance] "[ 0.515674] usbcore: registered new interface driver usbserial" #310: +1211592933 [appliance] "[ 0.516453] usbcore: registered new interface driver usbserial_generic" #311: +1212759283 [appliance] "[ 0.517412] usbserial: USB Serial support registered for generic" #312: +1212760960 [appliance] "[ 0.518265] i8042: PNP: No PS/2 controller found. Probing ports directly." #313: +1215486897 [appliance] "[ 0.520116] serio: i8042 KBD port at 0x60,0x64 irq 1" #314: +1215488569 [appliance] "[ 0.520861] serio: i8042 AUX port at 0x60,0x64 irq 12" #315: +1216574368 [appliance] "[ 0.522211] mousedev: PS/2 mouse device common for all mice" #316: +1219260529 [appliance] "[ 0.523888] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0" #317: +1223004935 [appliance] "[ 0.527628] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3" #318: +1224278563 [appliance] "[ 0.528930] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0" #319: +1224280190 [appliance] "[ 0.529876] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram" #320: +1225390876 [appliance] "[ 0.530916] device-mapper: uevent: version 1.0.3" #321: +1226482428 [appliance] "[ 0.532086] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2" #322: +1229067568 [appliance] "[ 0.533692] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com" #323: +1230910980 [appliance] "[ 0.535533] hidraw: raw HID events driver (C) Jiri Kosina" #324: +1230912626 [appliance] "[ 0.536411] usbcore: registered new interface driver usbhid" #325: +1232012542 [appliance] "[ 0.537157] usbhid: USB HID core driver" #326: +1233270119 [appliance] "[ 0.537923] drop_monitor: Initializing network drop monitor service" #327: +1233271789 [appliance] "[ 0.539004] ip_tables: (C) 2000-2006 Netfilter Core Team" #328: +1234383717 [appliance] "[ 0.539864] Initializing XFRM netlink socket" #329: +1236660202 [appliance] "[ 0.541324] NET: Registered protocol family 10" #330: +1238355865 [appliance] "[ 0.542978] mip6: Mobile IPv6" #331: +1238357392 [appliance] "[ 0.543421] NET: Registered protocol family 17" #332: +1240031307 [appliance] "[ 0.544653] microcode: CPU0 sig=0x306e4, pf=0x1, revision=0x1" #333: +1240032907 [appliance] "[ 0.545554] microcode: Microcode Update Driver: v2.01 , Peter Oruba" #334: +1241146626 [appliance] "[ 0.546742] AVX version of gcm_enc/dec engaged." #335: +1242253059 [appliance] "[ 0.547368] AES CTR mode by8 optimization enabled" #336: +1244399946 [appliance] "[ 0.549020] cryptomgr_test (85) used greatest stack depth: 13224 bytes left" #337: +1272213314 [appliance] "[ 0.576823] registered taskstats version 1" #338: +1272214838 [appliance] "[ 0.577420] Loading compiled-in X.509 certificates" #339: +1274492575 [appliance] "[ 0.579134] Loaded X.509 cert 'Fedora kernel signing key: d33a3fa294f19598ff71e1ac24c3cdc70d17052c'" #340: +1275598260 [appliance] "[ 0.580358] cryptomgr_test (100) used greatest stack depth: 12696 bytes left" #341: +1276874613 [appliance] "[ 0.581495] zswap: loaded using pool lzo/zbud" #342: +1278972542 [appliance] "[ 0.583595] Magic number: 8:713:875" #343: +1278974020 [appliance] "[ 0.584215] rtc_cmos rtc_cmos: setting system clock to 2016-03-22 07:51:49 UTC (1458633109)" #344: +1367002933 [appliance] "[ 0.671584] Freeing unused kernel memory: 3536K (ffffffff81f76000 - ffffffff822ea000)" #345: +1368123704 [appliance] "[ 0.672770] Write protecting the kernel read-only data: 14336k" #346: +1370816056 [appliance] "[ 0.675421] Freeing unused kernel memory: 1480K (ffff88000188e000 - ffff880001a00000)" #347: +1373392494 [appliance] "[ 0.678011] Freeing unused kernel memory: 436K (ffff880001d93000 - ffff880001e00000)" #348: +1375398266 [appliance] "supermin: mounting /proc" #349: +1375399652 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 glibc" #350: +1376613671 [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=screen guestfs_boot_analysis=1" #351: +1377728365 [appliance] "supermin: uptime: 0.47 0.13" #352: +1378926455 [appliance] "supermin: mounting /sys" #353: +1378927781 [appliance] "supermin: internal insmod crc32-pclmul.ko" #354: +1381752651 [appliance] "supermin: internal insmod crc32c-intel.ko" #355: +1383710837 [appliance] "supermin: internal insmod crct10dif-pclmul.ko" #356: +1385548347 [appliance] "supermin: internal insmod crc32.ko" #357: +1387381732 [appliance] "supermin: internal insmod virtio.ko" #358: +1389251564 [appliance] "supermin: internal insmod virtio_ring.ko" #359: +1391097918 [appliance] "supermin: internal insmod virtio_blk.ko" #360: +1393203966 [appliance] "supermin: internal insmod virtio-rng.ko" #361: +1395002001 [appliance] "supermin: internal insmod virtio_console.ko" #362: +1397304849 [appliance] "supermin: internal insmod virtio_net.ko" #363: +1399586120 [appliance] "supermin: internal insmod virtio_scsi.ko" #364: +1401672039 [appliance] "supermin: internal insmod virtio_balloon.ko" #365: +1403576642 [appliance] "supermin: internal insmod virtio_input.ko" #366: +1405425338 [appliance] "supermin: internal insmod virtio_mmio.ko" #367: +1407290772 [appliance] "supermin: internal insmod virtio_pci.ko" #368: +1410030222 [appliance] "[ 0.714645] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10" #369: +1410031606 [appliance] "[ 0.715700] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver" #370: +1413446089 [appliance] "[ 0.718082] scsi host2: Virtio SCSI HBA" #371: +1415014291 [appliance] "[ 0.719670] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11" #372: +1415015760 [appliance] "[ 0.720726] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver" #373: +1421801874 [appliance] "[ 0.726360] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #374: +1451892452 [appliance] "[ 0.756494] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #375: +1589656692 [appliance] "[ 0.892234] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)" #376: +1592018339 [appliance] "[ 0.896681] sd 2:0:0:0: Attached scsi generic sg0 type 0" #377: +1592019219 [appliance] "[ 0.897730] sd 2:0:0:0: [sda] Write Protect is off" #378: +1594580829 [appliance] "[ 0.899197] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #379: +1595669919 [appliance] "[ 0.900655] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)" #380: +1596763363 [appliance] "[ 0.901983] sd 2:0:1:0: [sdb] Write Protect is off" #381: +1597851692 [appliance] "[ 0.902743] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #382: +1600129363 [appliance] "[ 0.904802] sd 2:0:1:0: Attached scsi generic sg1 type 0" #383: +1604918655 [appliance] "[ 0.909569] Dev sda: unable to read RDB block 8" #384: +1604919183 [appliance] "[ 0.910187] sda: unable to read partition table" #385: +1606002150 [appliance] "[ 0.910830] sda: partition table beyond EOD, enabling native capacity" #386: +1607769962 [appliance] "[ 0.912441] sd 2:0:1:0: [sdb] Attached SCSI disk" #387: +1609306165 [appliance] "[ 0.913965] Dev sda: unable to read RDB block 8" #388: +1609306751 [appliance] "[ 0.914595] sda: unable to read partition table" #389: +1610396672 [appliance] "[ 0.915216] sda: partition table beyond EOD, truncated" #390: +1612216354 [appliance] "[ 0.916876] sd 2:0:0:0: [sda] Attached SCSI disk" #391: +1612216919 [appliance] "supermin: internal insmod crc-ccitt.ko" #392: +1614503022 [appliance] "supermin: internal insmod crc-itu-t.ko" #393: +1616161878 [appliance] "supermin: internal insmod crc8.ko" #394: +1617757303 [appliance] "supermin: internal insmod libcrc32c.ko" #395: +1619795173 [appliance] "supermin: picked /sys/block/sdb/dev as root device" #396: +1620951656 [appliance] "supermin: creating /dev/root as block special 8:16" #397: +1620952145 [appliance] "supermin: mounting new root on /root" #398: +1623486203 [appliance] "[ 0.928149] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem" #399: +1645723123 [appliance] "[ 0.950320] EXT4-fs (sdb): mounted filesystem without journal. Opts: " #400: +1645725297 [appliance] "supermin: chroot" #401: +1681388834 [appliance] "Starting /init script ..." #402: +1828675662 [appliance] "[ 1.133273] ldconfig (378) used greatest stack depth: 11968 bytes left" #403: +1876088063 [appliance] "[ 1.180717] random: systemd-tmpfile urandom read with 68 bits of entropy available" #404: +1878535546 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m" #405: +1881250035 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m" #406: +1881250912 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m" #407: +1882354723 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m" #408: +1883452312 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m" #409: +1884549108 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:34] Failed to replace specifiers: /var/log/journal/%m" #410: +1885638004 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:35] Failed to replace specifiers: /var/log/journal/%m" #411: +1889158404 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd" #412: +1894204187 [appliance] "starting version 222" #413: +2029036743 [appliance] "[ 1.333656] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9" #414: +2034391164 [appliance] "[ 1.339059] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0" #415: +2121796247 [appliance] "[ 1.426393] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e452ea631d, max_idle_ns: 440795244572 ns" #416: +2165014738 [appliance] "[ 1.469664] random: nonblocking pool is initialized" #417: +2270240140 [appliance] "[ 1.574844] input: PC Speaker as /devices/platform/pcspkr/input/input4" #418: +2328401728 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline" #419: +2333790368 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline" #420: +2338906840 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline" #421: +2340592201 [appliance] "[ 1.645217] systemd-udevd (400) used greatest stack depth: 11784 bytes left" #422: +2343266219 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline" #423: +2347634987 [appliance] "+ guestfs_boot_analysis=1" #424: +2348794831 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline" #425: +2351030072 [appliance] "+ eval" #426: +2351031207 [appliance] "+ grep -sq selinux=1 /proc/cmdline" #427: +2353534778 [appliance] "+ shopt -s nullglob" #428: +2353536105 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #429: +2354628957 [appliance] "+ echo 300" #430: +2354630050 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #431: +2355817285 [appliance] "+ echo 300" #432: +2355818709 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #433: +2356898351 [appliance] "+ echo noop" #434: +2358317566 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #435: +2358319023 [appliance] "+ echo noop" #436: +2358319363 [appliance] "+ shopt -u nullglob" #437: +2359411500 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host" #438: +2364011384 [appliance] "+ ip link set dev lo up" #439: +2366565376 [appliance] "[ 1.671189] ip (422) used greatest stack depth: 11728 bytes left" #440: +2366566849 [appliance] "+ test '' = 1" #441: +2367729387 [appliance] "+ mdadm -As --auto=yes --run" #442: +2377269850 [appliance] "mdadm: No arrays found in config file or automatically" #443: +2377271290 [appliance] "+ modprobe dm_mod" #444: +2381236506 [appliance] "+ lvmetad" #445: +2389871324 [appliance] "+ lvm vgchange -aay --sysinit" #446: +2400979422 [appliance] " lvmetad is not active yet, using direct activation during sysinit" #447: +2406971930 [appliance] "+ ldmtool create all" #448: +2416128801 [appliance] "[" #449: +2416130175 [appliance] "]" #450: +2418044488 [appliance] "+ test 1 = 1" #451: +2418045818 [appliance] "+ test 1 '!=' 1" #452: +2418046136 [appliance] "+ test '' = 1" #453: +2418046469 [appliance] "+ cmd=guestfsd" #454: +2419164045 [appliance] "+ test x '!=' x" #455: +2419165194 [appliance] "+ test 1 = 1" #456: +2419165534 [appliance] "+ cmd='guestfsd --verbose'" #457: +2419165794 [appliance] "+ test '' = 1" #458: +2420267807 [appliance] "+ echo guestfsd --verbose" #459: +2420268929 [appliance] "guestfsd --verbose" #460: +2420269206 [appliance] "+ guestfsd --verbose" #461: +2437839248 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'" #462: +2437841431 [appliance] "udevadm --debug settle" #463: +2443941091 [appliance] "calling: settle" #464: +2444070625 [launch_done] "launch done callback" #465: +2444083238 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG" #466: +2444085021 [library] "appliance is up" #467: +2444120821 [trace] "launch = 0" #468: +2444122544 [trace] "close" #469: +2444124069 [library] "closing guestfs handle 0xc407a0 (state 2)" #470: +2444127711 [trace] "internal_autosync" #471: +2447645879 [appliance] "guestfsd: main_loop: new request, len 0x28" #472: +2447647349 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0" #473: +2448760336 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0" #474: +2449882289 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0" #475: +2451013887 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=93972k,mode=755 freq=0 passno=0" #476: +2452135294 [appliance] "umount-all: /proc/mounts: fsname=/dev dir=/dev type=devtmpfs opts=rw,relatime,size=231628k,nr_inodes=57907,mode=755 freq=0 passno=0" #477: +2458494597 [appliance] "fsync /dev/sda" #478: +2458496170 [appliance] "guestfsd: main_loop: proc 282 (internal_autosync) took 0.01 seconds" #479: +2459593395 [trace] "internal_autosync = 0" #480: +2459597216 [library] "sending SIGTERM to process 5492" #481: +2474225981 [close] "close callback" #482: +2474238598 [library] "command: run: rm" #483: +2474240524 [library] "command: run: \ -rf /home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfs7dFFfg" #484: +2476100442 [library] "command: run: rm" #485: +2476101893 [library] "command: run: \ -rf /tmp/libguestfsQeqi9r" pass 1 number of events collected 486 elapsed time 2445539058 ns #0: +195367 [trace] "launch" #1: +198333 [trace] "version" #2: +214423 [trace] "version = " #3: +216702 [trace] "get_backend" #4: +218607 [trace] "get_backend = "direct"" #5: +220143 [library] "launch: program=boot-analysis" #6: +221234 [library] "launch: version=1.33.15" #7: +221966 [library] "launch: backend registered: unix" #8: +222534 [library] "launch: backend registered: uml" #9: +223059 [library] "launch: backend registered: libvirt" #10: +223754 [library] "launch: backend registered: direct" #11: +224346 [library] "launch: backend=direct" #12: +224884 [library] "launch: tmpdir=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsJPl54I" #13: +255323 [library] "launch: umask=0002" #14: +256367 [library] "launch: euid=1000" #15: +271349 [trace] "get_backend_setting "force_tcg"" #16: +276337 [trace] "get_backend_setting = NULL (error)" #17: +284656 [trace] "get_cachedir" #18: +286877 [trace] "get_cachedir = "/home/kchamart/src/rwmj-fork-libguestfs/tmp"" #19: +303204 [library] "begin building supermin appliance" #20: +304044 [library] "run supermin" #21: +307284 [library] "command: run: /home/kchamart/src/supermin/src/supermin" #22: +308116 [library] "command: run: \ --build" #23: +308732 [library] "command: run: \ --verbose" #24: +309242 [library] "command: run: \ --if-newer" #25: +309926 [library] "command: run: \ --lock /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #26: +310600 [library] "command: run: \ --copy-kernel" #27: +311207 [library] "command: run: \ -f ext2" #28: +311862 [library] "command: run: \ --host-cpu x86_64" #29: +312437 [library] "command: run: \ /home/kchamart/src/rwmj-fork-libguestfs/appliance/supermin.d" #30: +313127 [library] "command: run: \ -o /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d" #31: +11923724 [appliance] "supermin: version: 5.1.15" #32: +11925365 [appliance] "supermin: rpm: detected RPM version 4.13" #33: +11925752 [appliance] "supermin: package handler: fedora/rpm" #34: +11926587 [appliance] "supermin: acquiring lock on /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #35: +11927314 [appliance] "supermin: if-newer: output does not need rebuilding" #36: +17077832 [library] "finished building supermin appliance" #37: +17106355 [library] "begin testing qemu features" #38: +17115273 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #39: +17117148 [library] "command: run: \ -display none" #40: +17117866 [library] "command: run: \ -help" #41: +110233949 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #42: +110236339 [library] "command: run: \ -display none" #43: +110237414 [library] "command: run: \ -version" #44: +198740653 [library] "qemu version 2.5" #45: +198746139 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #46: +198748779 [library] "command: run: \ -display none" #47: +198753321 [library] "command: run: \ -machine accel=kvm:tcg" #48: +198755749 [library] "command: run: \ -device ?" #49: +294764974 [trace] "get_sockdir" #50: +294772829 [trace] "get_sockdir = "/tmp"" #51: +294913557 [library] "finished testing qemu features" #52: +294929456 [trace] "get_backend_setting "gdb"" #53: +294934680 [trace] "get_backend_setting = NULL (error)" #54: +297358263 [appliance] "[00295ms] /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64 \" #55: +297361249 [appliance] " -global virtio-blk-pci.scsi=off \" #56: +297363083 [appliance] " -nodefconfig \" #57: +297364133 [appliance] " -enable-fips \" #58: +297364959 [appliance] " -nodefaults \" #59: +297365976 [appliance] " -display none \" #60: +297366906 [appliance] " -machine accel=kvm:tcg \" #61: +297367769 [appliance] " -cpu host \" #62: +297368616 [appliance] " -m 500 \" #63: +297369449 [appliance] " -no-reboot \" #64: +297370279 [appliance] " -rtc driftfix=slew \" #65: +297371079 [appliance] " -no-hpet \" #66: +297371949 [appliance] " -global kvm-pit.lost_tick_policy=discard \" #67: +297373403 [appliance] " -kernel /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/kernel \" #68: +297374759 [appliance] " -initrd /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/initrd \" #69: +297375949 [appliance] " -device virtio-scsi-pci,id=scsi \" #70: +297376913 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsJPl54I/devnull1,cache=writeback,id=hd0,if=none \" #71: +297377946 [appliance] " -device scsi-hd,drive=hd0 \" #72: +297379083 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \" #73: +297380093 [appliance] " -device scsi-hd,drive=appliance \" #74: +297380933 [appliance] " -device virtio-serial-pci \" #75: +297381839 [appliance] " -serial stdio \" #76: +297382669 [appliance] " -device sga \" #77: +297383576 [appliance] " -chardev socket,path=/tmp/libguestfsZVwLG0/guestfsd.sock,id=channel0 \" #78: +297384723 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \" #79: +297386006 [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=screen guestfs_boot_analysis=1'" #80: +386286142 [appliance] "WARNING: Image format was not specified for '/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsJPl54I/devnull1' and probing guessed raw." #81: +386289882 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted." #82: +386292048 [appliance] " Specify the 'raw' format explicitly to remove the restrictions." #83: +501095488 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n" #84: +503159682 [appliance] "Google, Inc." #85: +503160986 [appliance] "Serial Graphics Adapter 11/03/11" #86: +503161736 [appliance] "SGABIOS $Id$ (pbonzini@yakj.usersys.redhat.com) Thu Nov 3 13:33:51 UTC 2011" #87: +504244874 [appliance] "Term: 80x24" #88: +504245884 [appliance] "4 0" #89: +504246327 [appliance] "\x1b[2J\x0dSeaBIOS (version rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org)" #90: +571861349 [appliance] "\x0dBooting from ROM..." #91: +576959530 [appliance] "\x0dProbing EDD (edd=off to disable)... ok" #92: +576962164 [appliance] "\x1b[2J" #93: +742245046 [appliance] "[ 0.000000] Initializing cgroup subsys cpuset" #94: +742247706 [appliance] "[ 0.000000] Initializing cgroup subsys cpu" #95: +742248279 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct" #96: +743359829 [appliance] "[ 0.000000] Linux version 4.4.5-300.fc23.x86_64+debug (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Thu Mar 10 17:37:59 UTC 2016" #97: +745594157 [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=screen guestfs_boot_analysis=1" #98: +747817886 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256" #99: +748933887 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'" #100: +750045338 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'" #101: +750046687 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'" #102: +751165357 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format." #103: +752282689 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches." #104: +753398358 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:" #105: +753399688 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable" #106: +754508739 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved" #107: +755619892 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved" #108: +756731332 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3ddfff] usable" #109: +757842431 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3de000-0x000000001f3fffff] reserved" #110: +757858496 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved" #111: +758967916 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved" #112: +760085375 [appliance] "[ 0.000000] NX (Execute Disable) protection: active" #113: +761190200 [appliance] "[ 0.000000] SMBIOS 2.8 present." #114: +761191430 [appliance] "[ 0.000000] Hypervisor detected: KVM" #115: +761191897 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3de max_arch_pfn = 0x400000000" #116: +762302341 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT " #117: +763409542 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f6bd0-0x000f6bdf] mapped at [ffff8800000f6bd0]" #118: +764519399 [appliance] "[ 0.000000] Scanning 1 areas for low memory corruption" #119: +764520734 [appliance] "[ 0.000000] Using GB pages for direct mapping" #120: +765636803 [appliance] "[ 0.000000] RAMDISK: [mem 0x00ee3000-0x00ffffff]" #121: +765637825 [appliance] "[ 0.000000] No NUMA configuration found" #122: +766757410 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3ddfff]" #123: +767866076 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f3cb000-0x1f3ddfff]" #124: +767867420 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00" #125: +768978213 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f3bb001, primary cpu clock" #126: +770087235 [appliance] "[ 0.000000] kvm-clock: using sched offset of 211383227 cycles" #127: +770088620 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns" #128: +771195040 [appliance] "[ 0.000000] Zone ranges:" #129: +772303091 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]" #130: +773414010 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3ddfff]" #131: +773415681 [appliance] "[ 0.000000] Normal empty" #132: +774520366 [appliance] "[ 0.000000] Movable zone start for each node" #133: +774521666 [appliance] "[ 0.000000] Early memory node ranges" #134: +774522109 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]" #135: +775637478 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3ddfff]" #136: +776757293 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3ddfff]" #137: +777868135 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org" #138: +778986682 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4" #139: +778988061 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU" #140: +780119943 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 " #141: +780128283 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000" #142: +780128858 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)" #143: +781233079 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23" #144: +782341775 [appliance] "[ 0.000000] Processors: 1" #145: +782343241 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs" #146: +783457093 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]" #147: +783458476 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]" #148: +784569450 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]" #149: +785688052 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]" #150: +786795143 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices" #151: +786796498 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM" #152: +787907386 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns" #153: +789024655 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1" #154: +790141083 [appliance] "[ 0.000000] PERCPU: Embedded 483 pages/cpu @ffff88001f000000 s1937944 r8192 d32232 u2097152" #155: +791246740 [appliance] "[ 0.000000] KVM setup async PF for cpu 0" #156: +791248003 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00db40" #157: +792357324 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125562" #158: +793463707 [appliance] "[ 0.000000] Policy zone: DMA32" #159: +793464971 [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=screen guestfs_boot_analysis=1" #160: +795693192 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)" #161: +796803781 [appliance] "[ 0.000000] Memory: 463228K/511472K available (8747K kernel code, 1490K rwdata, 3660K rodata, 3536K init, 16580K bss, 48244K reserved, 0K cma-reserved)" #162: +799028410 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1" #163: +799044712 [appliance] "[ 0.000000] Running RCU self tests" #164: +800170720 [appliance] "[ 0.000000] Hierarchical RCU implementation." #165: +800172600 [appliance] "[ 0.000000] \x09RCU lockdep checking is enabled." #166: +801280725 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64." #167: +801282125 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1." #168: +802389218 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1" #169: +803502226 [appliance] "[ 0.000000] kmemleak: Kernel memory leak detector disabled" #170: +804621235 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16" #171: +804623001 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs" #172: +805730580 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0." #173: +805732283 [appliance] "[ 0.000000] Console: colour *CGA 80x25" #174: +806841652 [appliance] "[ 0.000000] console [ttyS0] enabled" #175: +806843384 [appliance] "[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar" #176: +807952036 [appliance] "[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8" #177: +807953748 [appliance] "[ 0.000000] ... MAX_LOCK_DEPTH: 48" #178: +809063545 [appliance] "[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191" #179: +809064915 [appliance] "[ 0.000000] ... CLASSHASH_SIZE: 4096" #180: +810175976 [appliance] "[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 32768" #181: +810177329 [appliance] "[ 0.000000] ... MAX_LOCKDEP_CHAINS: 65536" #182: +811285254 [appliance] "[ 0.000000] ... CHAINHASH_SIZE: 32768" #183: +811286605 [appliance] "[ 0.000000] memory used by lock dependency info: 8671 kB" #184: +812397868 [appliance] "[ 0.000000] per task-struct memory footprint: 2688 bytes" #185: +813489386 [appliance] "[ 0.000000] tsc: Detected 2099.998 MHz processor" #186: +814589839 [appliance] "[ 0.122194] Calibrating delay loop (skipped) preset value.. 4199.99 BogoMIPS (lpj=2099998)" #187: +815695376 [appliance] "[ 0.123379] pid_max: default: 32768 minimum: 301" #188: +816893256 [appliance] "[ 0.124096] Security Framework initialized" #189: +816895069 [appliance] "[ 0.124653] Yama: becoming mindful." #190: +816895935 [appliance] "[ 0.125132] SELinux: Disabled at boot." #191: +818000305 [appliance] "[ 0.125834] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)" #192: +819105473 [appliance] "[ 0.126930] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)" #193: +820213373 [appliance] "[ 0.127911] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)" #194: +821321091 [appliance] "[ 0.128791] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)" #195: +823606479 [appliance] "[ 0.130812] Initializing cgroup subsys io" #196: +823608022 [appliance] "[ 0.131391] Initializing cgroup subsys memory" #197: +824701198 [appliance] "[ 0.132302] Disabling memory control group subsystem" #198: +824702195 [appliance] "[ 0.132958] Initializing cgroup subsys devices" #199: +825806199 [appliance] "[ 0.133580] Initializing cgroup subsys freezer" #200: +826915686 [appliance] "[ 0.134185] Initializing cgroup subsys net_cls" #201: +826917326 [appliance] "[ 0.134782] Initializing cgroup subsys perf_event" #202: +828022120 [appliance] "[ 0.135410] Initializing cgroup subsys net_prio" #203: +828024494 [appliance] "[ 0.136006] Initializing cgroup subsys hugetlb" #204: +829131203 [appliance] "[ 0.136615] Initializing cgroup subsys pids" #205: +830945008 [appliance] "[ 0.138119] mce: CPU supports 10 MCE banks" #206: +830946901 [appliance] "[ 0.138740] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0" #207: +832049741 [appliance] "[ 0.139437] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0" #208: +848676063 [appliance] "[ 0.155844] Freeing SMP alternatives memory: 28K (ffffffff822ea000 - ffffffff822f1000)" #209: +853977274 [appliance] "[ 0.161165] ftrace: allocating 29768 entries in 117 pages" #210: +892768902 [appliance] "[ 0.199936] x2apic enabled" #211: +892770624 [appliance] "[ 0.200599] Switched APIC routing to physical x2apic." #212: +895324893 [appliance] "[ 0.202497] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1" #213: +895326776 [appliance] "[ 0.203303] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2620 v2 @ 2.10GHz (family: 0x6, model: 0x3e, stepping: 0x4)" #214: +896450574 [appliance] "[ 0.204676] Performance Events: 16-deep LBR, IvyBridge events, Intel PMU driver." #215: +897559462 [appliance] "[ 0.205722] ... version: 2" #216: +898667351 [appliance] "[ 0.206233] ... bit width: 48" #217: +898668654 [appliance] "[ 0.206768] ... generic registers: 4" #218: +899775613 [appliance] "[ 0.207281] ... value mask: 0000ffffffffffff" #219: +899776991 [appliance] "[ 0.207969] ... max period: 000000007fffffff" #220: +900885319 [appliance] "[ 0.208649] ... fixed-purpose events: 3" #221: +900886696 [appliance] "[ 0.209166] ... event mask: 000000070000000f" #222: +904350056 [appliance] "[ 0.211540] x86: Booted up 1 node, 1 CPUs" #223: +904352017 [appliance] "[ 0.212071] smpboot: Total of 1 processors activated (4199.99 BogoMIPS)" #224: +907102306 [appliance] "[ 0.214286] devtmpfs: initialized" #225: +910949363 [appliance] "[ 0.218112] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns" #226: +912050742 [appliance] "[ 0.219629] atomic64_test: passed for x86-64 platform with CX8 and with SSE" #227: +913162234 [appliance] "[ 0.220539] pinctrl core: initialized pinctrl subsystem" #228: +914299633 [appliance] "[ 0.221513] RTC time: 7:51:51, date: 03/22/16" #229: +914301473 [appliance] "[ 0.222550] NET: Registered protocol family 16" #230: +916660381 [appliance] "[ 0.223869] cpuidle: using governor menu" #231: +916662296 [appliance] "[ 0.224891] PCI: Using configuration type 1 for base access" #232: +917768872 [appliance] "[ 0.226001] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off" #233: +926720770 [appliance] "[ 0.233887] ACPI: Interpreter disabled." #234: +926722587 [appliance] "[ 0.234946] vgaarb: loaded" #235: +927847115 [appliance] "[ 0.235640] SCSI subsystem initialized" #236: +929180241 [appliance] "[ 0.236374] usbcore: registered new interface driver usbfs" #237: +929182084 [appliance] "[ 0.237111] usbcore: registered new interface driver hub" #238: +930282310 [appliance] "[ 0.237857] usbcore: registered new device driver usb" #239: +931624757 [appliance] "[ 0.238817] PCI: Probing PCI hardware" #240: +931626511 [appliance] "[ 0.239464] PCI host bridge to bus 0000:00" #241: +932749089 [appliance] "[ 0.240016] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]" #242: +932750703 [appliance] "[ 0.240840] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]" #243: +933930101 [appliance] "[ 0.241774] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]" #244: +946393747 [appliance] "[ 0.253549] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]" #245: +948337425 [appliance] "[ 0.255564] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]" #246: +948338961 [appliance] "[ 0.256376] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]" #247: +949453879 [appliance] "[ 0.257285] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]" #248: +951673965 [appliance] "[ 0.258873] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI" #249: +951675790 [appliance] "[ 0.259802] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB" #250: +1004004291 [appliance] "[ 0.311154] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]" #251: +1005992005 [appliance] "[ 0.312906] NetLabel: Initializing" #252: +1005994048 [appliance] "[ 0.313643] NetLabel: domain hash size = 128" #253: +1005994915 [appliance] "[ 0.314186] NetLabel: protocols = UNLABELED CIPSOv4" #254: +1007105271 [appliance] "[ 0.314888] NetLabel: unlabeled traffic allowed by default" #255: +1008205703 [appliance] "[ 0.315849] clocksource: Switched to clocksource kvm-clock" #256: +1050651486 [appliance] "[ 0.357758] pnp: PnP ACPI: disabled" #257: +1057663931 [appliance] "[ 0.364763] NET: Registered protocol family 2" #258: +1058942814 [appliance] "[ 0.366136] TCP established hash table entries: 4096 (order: 3, 32768 bytes)" #259: +1058944813 [appliance] "[ 0.367152] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)" #260: +1060115823 [appliance] "[ 0.368242] TCP: Hash tables configured (established 4096 bind 4096)" #261: +1061218662 [appliance] "[ 0.369303] UDP hash table entries: 256 (order: 3, 49152 bytes)" #262: +1062330033 [appliance] "[ 0.370160] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)" #263: +1063434809 [appliance] "[ 0.371184] NET: Registered protocol family 1" #264: +1064585284 [appliance] "[ 0.371788] pci 0000:00:00.0: Limiting direct PCI/PCI transfers" #265: +1064587124 [appliance] "[ 0.372595] pci 0000:00:01.0: PIIX3: Enabling Passive Release" #266: +1065690561 [appliance] "[ 0.373393] pci 0000:00:01.0: Activating ISA DMA hang workarounds" #267: +1066789413 [appliance] "[ 0.374764] Unpacking initramfs..." #268: +1071258153 [appliance] "[ 0.378408] Freeing initrd memory: 1140K (ffff880000ee3000 - ffff880001000000)" #269: +1091083271 [appliance] "[ 0.398176] DMA-API: preallocated 65536 debug entries" #270: +1091086761 [appliance] "[ 0.398915] DMA-API: debugging enabled by kernel config" #271: +1092256863 [appliance] "[ 0.399909] platform rtc_cmos: registered platform RTC device (no PNP device found)" #272: +1093345094 [appliance] "[ 0.401563] Scanning for low memory corruption every 60 seconds" #273: +1096429469 [appliance] "[ 0.403595] futex hash table entries: 256 (order: 3, 32768 bytes)" #274: +1096431395 [appliance] "[ 0.404470] audit: initializing netlink subsys (disabled)" #275: +1097536254 [appliance] "[ 0.405296] audit: type=2000 audit(1458633112.263:1): initialized" #276: +1098655070 [appliance] "[ 0.406307] cryptomgr_test (27) used greatest stack depth: 14040 bytes left" #277: +1100882760 [appliance] "[ 0.408088] Initialise system trusted keyring" #278: +1100884674 [appliance] "[ 0.409168] HugeTLB registered 1 GB page size, pre-allocated 0 pages" #279: +1101999276 [appliance] "[ 0.410027] HugeTLB registered 2 MB page size, pre-allocated 0 pages" #280: +1112625036 [appliance] "[ 0.419805] zbud: loaded" #281: +1113803031 [appliance] "[ 0.420997] VFS: Disk quotas dquot_6.6.0" #282: +1113804856 [appliance] "[ 0.421673] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)" #283: +1117727480 [appliance] "[ 0.424912] Key type big_key registered" #284: +1117729293 [appliance] "[ 0.426020] cryptomgr_test (35) used greatest stack depth: 13688 bytes left" #285: +1122306822 [appliance] "[ 0.429465] cryptomgr_test (51) used greatest stack depth: 13280 bytes left" #286: +1126306718 [appliance] "[ 0.433467] NET: Registered protocol family 38" #287: +1126308565 [appliance] "[ 0.434119] Key type asymmetric registered" #288: +1127411794 [appliance] "[ 0.434677] Asymmetric key parser 'x509' registered" #289: +1127413483 [appliance] "[ 0.435504] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)" #290: +1128601526 [appliance] "[ 0.436830] io scheduler noop registered" #291: +1129707861 [appliance] "[ 0.437431] io scheduler deadline registered" #292: +1131029319 [appliance] "[ 0.438238] io scheduler cfq registered (default)" #293: +1133461676 [appliance] "[ 0.440634] pci_hotplug: PCI Hot Plug PCI Core version: 0.5" #294: +1133463497 [appliance] "[ 0.441397] pciehp: PCI Express Hot Plug Controller Driver version: 0.4" #295: +1134562656 [appliance] "[ 0.442684] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled" #296: +1161057694 [appliance] "[ 0.468224] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A" #297: +1169170357 [appliance] "[ 0.476309] Non-volatile memory driver v1.3" #298: +1169172231 [appliance] "[ 0.477030] Linux agpgart interface v0.103" #299: +1173763719 [appliance] "[ 0.480941] scsi host0: ata_piix" #300: +1173765582 [appliance] "[ 0.481819] scsi host1: ata_piix" #301: +1174869370 [appliance] "[ 0.482433] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14" #302: +1175978923 [appliance] "[ 0.483306] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15" #303: +1177821885 [appliance] "[ 0.484988] libphy: Fixed MDIO Bus: probed" #304: +1177823671 [appliance] "[ 0.485734] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver" #305: +1178925797 [appliance] "[ 0.486622] ehci-pci: EHCI PCI platform driver" #306: +1180056578 [appliance] "[ 0.487255] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver" #307: +1180058362 [appliance] "[ 0.488068] ohci-pci: OHCI PCI platform driver" #308: +1181166945 [appliance] "[ 0.488702] uhci_hcd: USB Universal Host Controller Interface driver" #309: +1182271977 [appliance] "[ 0.489966] usbcore: registered new interface driver usbserial" #310: +1183373062 [appliance] "[ 0.490732] usbcore: registered new interface driver usbserial_generic" #311: +1183374588 [appliance] "[ 0.491674] usbserial: USB Serial support registered for generic" #312: +1184552407 [appliance] "[ 0.492540] i8042: PNP: No PS/2 controller found. Probing ports directly." #313: +1187251722 [appliance] "[ 0.494423] serio: i8042 KBD port at 0x60,0x64 irq 1" #314: +1187255738 [appliance] "[ 0.495148] serio: i8042 AUX port at 0x60,0x64 irq 12" #315: +1188366113 [appliance] "[ 0.496507] mousedev: PS/2 mouse device common for all mice" #316: +1190976174 [appliance] "[ 0.498147] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0" #317: +1194735474 [appliance] "[ 0.501909] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3" #318: +1196043563 [appliance] "[ 0.503193] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0" #319: +1196044959 [appliance] "[ 0.504125] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram" #320: +1197157225 [appliance] "[ 0.505188] device-mapper: uevent: version 1.0.3" #321: +1198267593 [appliance] "[ 0.506385] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2" #322: +1200847237 [appliance] "[ 0.507976] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com" #323: +1202613820 [appliance] "[ 0.509780] hidraw: raw HID events driver (C) Jiri Kosina" #324: +1202615258 [appliance] "[ 0.510663] usbcore: registered new interface driver usbhid" #325: +1203730118 [appliance] "[ 0.511396] usbhid: USB HID core driver" #326: +1204932874 [appliance] "[ 0.512135] drop_monitor: Initializing network drop monitor service" #327: +1204946229 [appliance] "[ 0.513168] ip_tables: (C) 2000-2006 Netfilter Core Team" #328: +1206057482 [appliance] "[ 0.514016] Initializing XFRM netlink socket" #329: +1207148222 [appliance] "[ 0.515400] NET: Registered protocol family 10" #330: +1209867375 [appliance] "[ 0.517035] mip6: Mobile IPv6" #331: +1209868709 [appliance] "[ 0.517514] NET: Registered protocol family 17" #332: +1211509200 [appliance] "[ 0.518680] microcode: CPU0 sig=0x306e4, pf=0x1, revision=0x1" #333: +1211510626 [appliance] "[ 0.519587] microcode: Microcode Update Driver: v2.01 , Peter Oruba" #334: +1212615309 [appliance] "[ 0.520769] AVX version of gcm_enc/dec engaged." #335: +1213727245 [appliance] "[ 0.521392] AES CTR mode by8 optimization enabled" #336: +1215793461 [appliance] "[ 0.522961] cryptomgr_test (85) used greatest stack depth: 13224 bytes left" #337: +1242093936 [appliance] "[ 0.549256] registered taskstats version 1" #338: +1242095414 [appliance] "[ 0.549865] Loading compiled-in X.509 certificates" #339: +1244397010 [appliance] "[ 0.551589] Loaded X.509 cert 'Fedora kernel signing key: d33a3fa294f19598ff71e1ac24c3cdc70d17052c'" #340: +1245577135 [appliance] "[ 0.552778] cryptomgr_test (100) used greatest stack depth: 12696 bytes left" #341: +1246712036 [appliance] "[ 0.553926] zswap: loaded using pool lzo/zbud" #342: +1248839069 [appliance] "[ 0.555999] Magic number: 8:713:875" #343: +1248840475 [appliance] "[ 0.556644] rtc_cmos rtc_cmos: setting system clock to 2016-03-22 07:51:51 UTC (1458633111)" #344: +1335974331 [appliance] "[ 0.643118] Freeing unused kernel memory: 3536K (ffffffff81f76000 - ffffffff822ea000)" #345: +1335976165 [appliance] "[ 0.644161] Write protecting the kernel read-only data: 14336k" #346: +1339239918 [appliance] "[ 0.646396] Freeing unused kernel memory: 1480K (ffff88000188e000 - ffff880001a00000)" #347: +1341555280 [appliance] "[ 0.648709] Freeing unused kernel memory: 436K (ffff880001d93000 - ffff880001e00000)" #348: +1343552453 [appliance] "supermin: mounting /proc" #349: +1343553921 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 glibc" #350: +1344869845 [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=screen guestfs_boot_analysis=1" #351: +1345976251 [appliance] "supermin: uptime: 0.46 0.13" #352: +1347112496 [appliance] "supermin: mounting /sys" #353: +1347113886 [appliance] "supermin: internal insmod crc32-pclmul.ko" #354: +1349967975 [appliance] "supermin: internal insmod crc32c-intel.ko" #355: +1351975646 [appliance] "supermin: internal insmod crct10dif-pclmul.ko" #356: +1353919156 [appliance] "supermin: internal insmod crc32.ko" #357: +1355775197 [appliance] "supermin: internal insmod virtio.ko" #358: +1357493703 [appliance] "supermin: internal insmod virtio_ring.ko" #359: +1359371990 [appliance] "supermin: internal insmod virtio_blk.ko" #360: +1361492435 [appliance] "supermin: internal insmod virtio-rng.ko" #361: +1363331601 [appliance] "supermin: internal insmod virtio_console.ko" #362: +1365715007 [appliance] "supermin: internal insmod virtio_net.ko" #363: +1367998229 [appliance] "supermin: internal insmod virtio_scsi.ko" #364: +1370139544 [appliance] "supermin: internal insmod virtio_balloon.ko" #365: +1372135292 [appliance] "supermin: internal insmod virtio_input.ko" #366: +1374002903 [appliance] "supermin: internal insmod virtio_mmio.ko" #367: +1375874551 [appliance] "supermin: internal insmod virtio_pci.ko" #368: +1378469209 [appliance] "[ 0.685626] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10" #369: +1378470617 [appliance] "[ 0.686650] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver" #370: +1381955175 [appliance] "[ 0.689142] scsi host2: Virtio SCSI HBA" #371: +1383590075 [appliance] "[ 0.690717] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11" #372: +1383591485 [appliance] "[ 0.691767] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver" #373: +1389142727 [appliance] "[ 0.696263] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #374: +1421012547 [appliance] "[ 0.728125] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #375: +1561053706 [appliance] "[ 0.868161] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)" #376: +1562384549 [appliance] "[ 0.869568] sd 2:0:0:0: Attached scsi generic sg0 type 0" #377: +1565434230 [appliance] "[ 0.870597] sd 2:0:0:0: [sda] Write Protect is off" #378: +1567378218 [appliance] "[ 0.874584] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)" #379: +1567379047 [appliance] "[ 0.875654] sd 2:0:1:0: Attached scsi generic sg1 type 0" #380: +1569564757 [appliance] "[ 0.876748] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #381: +1570652737 [appliance] "[ 0.878076] sd 2:0:1:0: [sdb] Write Protect is off" #382: +1570653563 [appliance] "[ 0.878875] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #383: +1578106616 [appliance] "[ 0.885307] sd 2:0:1:0: [sdb] Attached SCSI disk" #384: +1578107266 [appliance] "[ 0.885982] Dev sda: unable to read RDB block 8" #385: +1579204777 [appliance] "[ 0.886594] sda: unable to read partition table" #386: +1579205385 [appliance] "[ 0.887215] sda: partition table beyond EOD, enabling native capacity" #387: +1582277268 [appliance] "[ 0.889481] Dev sda: unable to read RDB block 8" #388: +1582277948 [appliance] "[ 0.890097] sda: unable to read partition table" #389: +1583357513 [appliance] "[ 0.890713] sda: partition table beyond EOD, truncated" #390: +1585130866 [appliance] "[ 0.892333] sd 2:0:0:0: [sda] Attached SCSI disk" #391: +1585131523 [appliance] "supermin: internal insmod crc-ccitt.ko" #392: +1587418087 [appliance] "supermin: internal insmod crc-itu-t.ko" #393: +1588966462 [appliance] "supermin: internal insmod crc8.ko" #394: +1590526653 [appliance] "supermin: internal insmod libcrc32c.ko" #395: +1592585751 [appliance] "supermin: picked /sys/block/sdb/dev as root device" #396: +1593778099 [appliance] "supermin: creating /dev/root as block special 8:16" #397: +1593778634 [appliance] "supermin: mounting new root on /root" #398: +1595844324 [appliance] "[ 0.903057] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem" #399: +1618026509 [appliance] "[ 0.925181] EXT4-fs (sdb): mounted filesystem without journal. Opts: " #400: +1618029204 [appliance] "supermin: chroot" #401: +1652247203 [appliance] "Starting /init script ..." #402: +1796907144 [appliance] "[ 1.104064] ldconfig (378) used greatest stack depth: 12224 bytes left" #403: +1843852312 [appliance] "[ 1.151041] random: systemd-tmpfile urandom read with 69 bits of entropy available" #404: +1846285356 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m" #405: +1849059383 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m" #406: +1849060330 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m" #407: +1850164850 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m" #408: +1851288862 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m" #409: +1852386547 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:34] Failed to replace specifiers: /var/log/journal/%m" #410: +1853498368 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:35] Failed to replace specifiers: /var/log/journal/%m" #411: +1856758449 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd" #412: +1861774598 [appliance] "starting version 222" #413: +1961485795 [appliance] "[ 1.268642] udevadm (395) used greatest stack depth: 12000 bytes left" #414: +1988002264 [appliance] "[ 1.295186] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9" #415: +1990901600 [appliance] "[ 1.298115] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0" #416: +2092210767 [appliance] "[ 1.399347] random: nonblocking pool is initialized" #417: +2094806954 [appliance] "[ 1.401967] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e452ea631d, max_idle_ns: 440795244572 ns" #418: +2245926915 [appliance] "[ 1.553052] input: PC Speaker as /devices/platform/pcspkr/input/input4" #419: +2298788085 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline" #420: +2303101422 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline" #421: +2304391481 [appliance] "[ 1.611583] systemd-udevd (399) used greatest stack depth: 11440 bytes left" #422: +2307283299 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline" #423: +2312751500 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline" #424: +2318047644 [appliance] "+ guestfs_boot_analysis=1" #425: +2318049012 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline" #426: +2321398115 [appliance] "+ eval" #427: +2321399505 [appliance] "+ grep -sq selinux=1 /proc/cmdline" #428: +2323918121 [appliance] "+ shopt -s nullglob" #429: +2323919466 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #430: +2325014453 [appliance] "+ echo 300" #431: +2325015541 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #432: +2326167342 [appliance] "+ echo 300" #433: +2326168703 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #434: +2327253004 [appliance] "+ echo noop" #435: +2328776404 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #436: +2328777774 [appliance] "+ echo noop" #437: +2328778137 [appliance] "+ shopt -u nullglob" #438: +2329869846 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host" #439: +2334590618 [appliance] "+ ip link set dev lo up" #440: +2337360015 [appliance] "+ test '' = 1" #441: +2337361250 [appliance] "+ mdadm -As --auto=yes --run" #442: +2347065614 [appliance] "mdadm: No arrays found in config file or automatically" #443: +2347067012 [appliance] "+ modprobe dm_mod" #444: +2351045783 [appliance] "+ lvmetad" #445: +2359591025 [appliance] "+ lvm vgchange -aay --sysinit" #446: +2370283380 [appliance] " lvmetad is not active yet, using direct activation during sysinit" #447: +2376312898 [appliance] "+ ldmtool create all" #448: +2385302972 [appliance] "[" #449: +2385304434 [appliance] "]" #450: +2387281809 [appliance] "+ test 1 = 1" #451: +2387283057 [appliance] "+ test 1 '!=' 1" #452: +2387283379 [appliance] "+ test '' = 1" #453: +2387283573 [appliance] "+ cmd=guestfsd" #454: +2388501732 [appliance] "+ test x '!=' x" #455: +2388502975 [appliance] "+ test 1 = 1" #456: +2388503298 [appliance] "+ cmd='guestfsd --verbose'" #457: +2388503486 [appliance] "+ test '' = 1" #458: +2389705348 [appliance] "+ echo guestfsd --verbose" #459: +2389706685 [appliance] "guestfsd --verbose" #460: +2389706944 [appliance] "+ guestfsd --verbose" #461: +2406616963 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'" #462: +2406618692 [appliance] "udevadm --debug settle" #463: +2412449640 [appliance] "calling: settle" #464: +2412514668 [launch_done] "launch done callback" #465: +2412520001 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG" #466: +2412521513 [library] "appliance is up" #467: +2412560898 [trace] "launch = 0" #468: +2412562388 [trace] "close" #469: +2412563694 [library] "closing guestfs handle 0xc43780 (state 2)" #470: +2412568776 [trace] "internal_autosync" #471: +2416084996 [appliance] "guestfsd: main_loop: new request, len 0x28" #472: +2416086949 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0" #473: +2417209180 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0" #474: +2418317351 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0" #475: +2419437057 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=93972k,mode=755 freq=0 passno=0" #476: +2420617903 [appliance] "umount-all: /proc/mounts: fsname=/dev dir=/dev type=devtmpfs opts=rw,relatime,size=231628k,nr_inodes=57907,mode=755 freq=0 passno=0" #477: +2425900879 [appliance] "fsync /dev/sda" #478: +2425902229 [appliance] "guestfsd: main_loop: proc 282 (internal_autosync) took 0.01 seconds" #479: +2427007425 [trace] "internal_autosync = 0" #480: +2427009748 [library] "sending SIGTERM to process 5519" #481: +2445537875 [close] "close callback" #482: +2445558273 [library] "command: run: rm" #483: +2445560479 [library] "command: run: \ -rf /home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsJPl54I" #484: +2447796669 [library] "command: run: rm" #485: +2447798431 [library] "command: run: \ -rf /tmp/libguestfsZVwLG0" Analyzing the results ... activity 0: name = run start - end = 0.0 - 2459696012.0 mean elapsed = 2459696013.0 variance = 206023105785025.0 s.d = 14353505.0 percent = 100.0 activity 1: name = supermin:build start - end = 109042.5 - 15907534.0 mean elapsed = 15798492.5 variance = 952840514360.2 s.d = 976135.5 percent = 0.6 activity 2: name = qemu:feature-detect start - end = 15935520.5 - 287868483.5 mean elapsed = 271932964.0 variance = 34506672080644.0 s.d = 5874238.0 percent = 11.1 activity 3: name = qemu start - end = 290197438.5 - 2459696012.0 mean elapsed = 2169498574.5 variance = 454703700107306.2 s.d = 21323782.5 percent = 88.2 activity 4: name = qemu:overhead start - end = 290197438.5 - 501232479.5 mean elapsed = 211035042.0 variance = 53328507153769.0 s.d = 7302637.0 percent = 8.6 activity 5: name = bios:overhead start - end = 501232480.5 - 744233149.0 mean elapsed = 243000669.5 variance = 542179659912.2 s.d = 736328.5 percent = 9.9 activity 6: name = sgabios start - end = 501232480.5 - 504499996.5 mean elapsed = 3267517.0 variance = 13613755684.0 s.d = 116678.0 percent = 0.1 activity 7: name = seabios start - end = 504499997.5 - 744233149.0 mean elapsed = 239733152.5 variance = 383966742150.2 s.d = 619650.5 percent = 9.7 activity 8: name = kernel start - end = 744233150.0 - 2459696012.0 mean elapsed = 1715462863.0 variance = 176486362723489.0 s.d = 13284817.0 percent = 69.7 activity 9: name = kernel:overhead start - end = 744233150.0 - 1359290870.5 mean elapsed = 615057721.5 variance = 220927481913270.2 s.d = 14863629.5 percent = 25.0 activity 10: name = supermin:mini-initrd start - end = 1359290871.5 - 1631691334.5 mean elapsed = 272400464.0 variance = 4304873882761.0 s.d = 2074819.0 percent = 11.1 activity 11: name = supermin: internal insmod crc32-pclmul.ko start - end = 1362834918.5 - 1365674397.0 mean elapsed = 2839479.5 variance = 213437490.2 s.d = 14609.5 percent = 0.1 activity 12: name = supermin: internal insmod crc32c-intel.ko start - end = 1365674398.0 - 1367657325.5 mean elapsed = 1982928.5 variance = 612191306.2 s.d = 24742.5 percent = 0.1 activity 13: name = supermin: internal insmod crct10dif-pclmul.ko start - end = 1367657326.5 - 1369547835.5 mean elapsed = 1890510.0 variance = 2809000000.0 s.d = 53000.0 percent = 0.1 activity 14: name = supermin: internal insmod crc32.ko start - end = 1369547836.5 - 1371392548.5 mean elapsed = 1844713.0 variance = 128323584.0 s.d = 11328.0 percent = 0.1 activity 15: name = supermin: internal insmod virtio.ko start - end = 1371392549.5 - 1373186717.5 mean elapsed = 1794169.0 variance = 5724889569.0 s.d = 75663.0 percent = 0.1 activity 16: name = supermin: internal insmod virtio_ring.ko start - end = 1373186718.5 - 1375049038.0 mean elapsed = 1862320.5 variance = 254929122.2 s.d = 15966.5 percent = 0.1 activity 17: name = supermin: internal insmod virtio_blk.ko start - end = 1375049039.0 - 1377162284.5 mean elapsed = 2113246.5 variance = 51818402.2 s.d = 7198.5 percent = 0.1 activity 18: name = supermin: internal insmod virtio-rng.ko start - end = 1377162285.5 - 1378980885.0 mean elapsed = 1818600.5 variance = 422939790.2 s.d = 20565.5 percent = 0.1 activity 19: name = supermin: internal insmod virtio_console.ko start - end = 1378980886.0 - 1381324012.0 mean elapsed = 2343127.0 variance = 1622397841.0 s.d = 40279.0 percent = 0.1 activity 20: name = supermin: internal insmod virtio_net.ko start - end = 1381324013.0 - 1383606258.5 mean elapsed = 2282246.5 variance = 951600.2 s.d = 975.5 percent = 0.1 activity 21: name = supermin: internal insmod virtio_scsi.ko start - end = 1383606259.5 - 1385719875.5 mean elapsed = 2113617.0 variance = 767179204.0 s.d = 27698.0 percent = 0.1 activity 22: name = supermin: internal insmod virtio_balloon.ko start - end = 1385719876.5 - 1387670051.0 mean elapsed = 1950175.5 variance = 2076852756.2 s.d = 45572.5 percent = 0.1 activity 23: name = supermin: internal insmod virtio_input.ko start - end = 1387670052.0 - 1389528204.5 mean elapsed = 1858153.5 variance = 89444306.2 s.d = 9457.5 percent = 0.1 activity 24: name = supermin: internal insmod virtio_mmio.ko start - end = 1389528205.5 - 1391396745.5 mean elapsed = 1868541.0 variance = 9653449.0 s.d = 3107.0 percent = 0.1 activity 25: name = supermin: internal insmod virtio_pci.ko start - end = 1391396746.5 - 1598488305.0 mean elapsed = 207091559.5 variance = 4689011295156.2 s.d = 2165412.5 percent = 8.4 activity 26: name = supermin: internal insmod crc-ccitt.ko start - end = 1598488306.0 - 1600774638.5 mean elapsed = 2286333.5 variance = 53130.2 s.d = 230.5 percent = 0.1 activity 27: name = supermin: internal insmod crc-itu-t.ko start - end = 1600774639.5 - 1602378254.0 mean elapsed = 1603615.5 variance = 3051512840.2 s.d = 55240.5 percent = 0.1 activity 28: name = supermin: internal insmod crc8.ko start - end = 1602378255.0 - 1603Linux host20-rack09.scale.openstack.engineering.redhat.com 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) Xeon(R) CPU E5-2620 v2 @ 2.10GHz 956062.0 mean elapsed = 1577808.0 variance = 310358689.0 s.d = 17617.0 percent = 0.1 activity 29: name = supermin: internal insmod libcrc32c.ko start - end = 1603956063.0 - 1606004546.0 mean elapsed = 2048484.0 variance = 112656996.0 s.d = 10614.0 percent = 0.1 activity 30: name = /init start - end = 1631691335.5 - 2403648500.0 mean elapsed = 771957165.5 variance = 2199501074112.2 s.d = 1483071.5 percent = 31.4 activity 31: name = bash:overhead start - end = 1631691335.5 - 1666632102.5 mean elapsed = 34940768.0 variance = 522395027361.0 s.d = 722769.0 percent = 1.4 activity 32: name = guestfsd start - end = 2403648501.0 - 2442011822.0 mean elapsed = 38363322.0 variance = 932655679081.0 s.d = 965741.0 percent = 1.6 activity 33: name = shutdown start - end = 2428156551.0 - 2459696012.0 mean elapsed = 31539462.0 variance = 2062167800625.0 s.d = 1436025.0 percent = 1.3 libguestfs 1.33.15 Host: Appliance: qemu version 2.5 \x1b[2J\x0dSeaBIOS (version rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org) [ 0.000000] Linux version 4.4.5-300.fc23.x86_64+debug (mockbuild@bkernel02.phx2.fedoraproject.org) (gcc version 5.3.1 20151207 (Red Hat 5.3.1-2) (GCC) ) #1 SMP Thu Mar 10 17:37:59 UTC 2016 supermin: ext2 mini initrd starting up: 5.1.15 glibc 0.000000s: ▲ run mean:2.459696s ±14.4ms (100.0%) 0.000109s: │ ▲ supermin:build mean:0.015798s ±1.0ms (0.6%) │ │ 0.015908s: │ ▼ 0.015936s: │ ▲ qemu:feature-detect mean:0.271933s ±5.9ms (11.1%) │ │ 0.287868s: │ ▼ │ 0.290197s: │ ▲ ▲ qemu mean:2.169499s ±21.3ms (88.2%) qemu:overhead mean:0.211035s ±7.3ms (8.6%) │ │ │ 0.501232s: │ │ ▼ 0.501232s: │ │ ▲ ▲ bios:overhead mean:0.243001s ±0.7ms (9.9%) sgabios mean:0.003268s ±0.1ms (0.1%) │ │ │ │ 0.504500s: │ │ │ ▼ 0.504500s: │ │ │ ▲ seabios mean:0.239733s ±0.6ms (9.7%) │ │ │ │ 0.744233s: │ │ ▼ ▼ 0.744233s: │ │ ▲ ▲ kernel mean:1.715463s ±13.3ms (69.7%) kernel:overhead mean:0.615058s ±14.9ms (25.0%) │ │ │ │ 1.359291s: │ │ │ ▼ 1.359291s: │ │ │ ▲ supermin:mini-initrd mean:0.272400s ±2.1ms (11.1%) │ │ │ │ 1.362835s: │ │ │ │ ▲ supermin: internal insmod crc32-pclmul.ko mean:0.002839s ±0.0ms (0.1%) │ │ │ │ │ 1.365674s: │ │ │ │ ▼ 1.365674s: │ │ │ │ ▲ supermin: internal insmod crc32c-intel.ko mean:0.001983s ±0.0ms (0.1%) │ │ │ │ │ 1.367657s: │ │ │ │ ▼ 1.367657s: │ │ │ │ ▲ supermin: internal insmod crct10dif-pclmul.ko mean:0.001891s ±0.1ms (0.1%) │ │ │ │ │ 1.369548s: │ │ │ │ ▼ 1.369548s: │ │ │ │ ▲ supermin: internal insmod crc32.ko mean:0.001845s ±0.0ms (0.1%) │ │ │ │ │ 1.371393s: │ │ │ │ ▼ 1.371393s: │ │ │ │ ▲ supermin: internal insmod virtio.ko mean:0.001794s ±0.1ms (0.1%) │ │ │ │ │ 1.373187s: │ │ │ │ ▼ 1.373187s: │ │ │ │ ▲ supermin: internal insmod virtio_ring.ko mean:0.001862s ±0.0ms (0.1%) │ │ │ │ │ 1.375049s: │ │ │ │ ▼ 1.375049s: │ │ │ │ ▲ supermin: internal insmod virtio_blk.ko mean:0.002113s ±0.0ms (0.1%) │ │ │ │ │ 1.377162s: │ │ │ │ ▼ 1.377162s: │ │ │ │ ▲ supermin: internal insmod virtio-rng.ko mean:0.001819s ±0.0ms (0.1%) │ │ │ │ │ 1.378981s: │ │ │ │ ▼ 1.378981s: │ │ │ │ ▲ supermin: internal insmod virtio_console.ko mean:0.002343s ±0.0ms (0.1%) │ │ │ │ │ 1.381324s: │ │ │ │ ▼ 1.381324s: │ │ │ │ ▲ supermin: internal insmod virtio_net.ko mean:0.002282s ±0.0ms (0.1%) │ │ │ │ │ 1.383606s: │ │ │ │ ▼ 1.383606s: │ │ │ │ ▲ supermin: internal insmod virtio_scsi.ko mean:0.002114s ±0.0ms (0.1%) │ │ │ │ │ 1.385720s: │ │ │ │ ▼ 1.385720s: │ │ │ │ ▲ supermin: internal insmod virtio_balloon.ko mean:0.001950s ±0.0ms (0.1%) │ │ │ │ │ 1.387670s: │ │ │ │ ▼ 1.387670s: │ │ │ │ ▲ supermin: internal insmod virtio_input.ko mean:0.001858s ±0.0ms (0.1%) │ │ │ │ │ 1.389528s: │ │ │ │ ▼ 1.389528s: │ │ │ │ ▲ supermin: internal insmod virtio_mmio.ko mean:0.001869s ±0.0ms (0.1%) │ │ │ │ │ 1.391397s: │ │ │ │ ▼ 1.391397s: │ │ │ │ ▲ supermin: internal insmod virtio_pci.ko mean:0.207092s ±2.2ms (8.4%) │ │ │ │ │ 1.598488s: │ │ │ │ ▼ 1.598488s: │ │ │ │ ▲ supermin: internal insmod crc-ccitt.ko mean:0.002286s ±0.0ms (0.1%) │ │ │ │ │ 1.600775s: │ │ │ │ ▼ 1.600775s: │ │ │ │ ▲ supermin: internal insmod crc-itu-t.ko mean:0.001604s ±0.1ms (0.1%) │ │ │ │ │ 1.602378s: │ │ │ │ ▼ 1.602378s: │ │ │ │ ▲ supermin: internal insmod crc8.ko mean:0.001578s ±0.0ms (0.1%) │ │ │ │ │ 1.603956s: │ │ │ │ ▼ 1.603956s: │ │ │ │ ▲ supermin: internal insmod libcrc32c.ko mean:0.002048s ±0.0ms (0.1%) │ │ │ │ │ 1.606005s: │ │ │ │ ▼ │ │ │ │ 1.631691s: │ │ │ ▼ 1.631691s: │ │ │ ▲ ▲ /init mean:0.771957s ±1.5ms (31.4%) bash:overhead mean:0.034941s ±0.7ms (1.4%) │ │ │ │ │ 1.666632s: │ │ │ │ ▼ │ │ │ │ 2.403649s: │ │ │ ▼ 2.403649s: │ │ │ ▲ guestfsd mean:0.038363s ±1.0ms (1.6%) │ │ │ │ 2.428157s: │ │ │ │ ▲ shutdown mean:0.031539s ±1.4ms (1.3%) │ │ │ │ │ 2.442012s: │ │ │ ▼ │ │ │ │ │ 2.459696s: ▼ ▼ ▼ ▼