Warming up the libguestfs cache ... Running the tests in 2 passes ... pass 1: 484 events collected in 2448785490 ns pass 2: 484 events collected in 2446303944 ns pass 0 number of events collected 484 elapsed time 2448785490 ns #0: +202547 [trace] "launch" #1: +206287 [trace] "version" #2: +212507 [trace] "version = " #3: +215662 [trace] "get_backend" #4: +217932 [trace] "get_backend = "direct"" #5: +220030 [library] "launch: program=boot-analysis" #6: +221395 [library] "launch: version=1.33.15" #7: +222215 [library] "launch: backend registered: unix" #8: +222902 [library] "launch: backend registered: uml" #9: +223545 [library] "launch: backend registered: libvirt" #10: +224147 [library] "launch: backend registered: direct" #11: +225203 [library] "launch: backend=direct" #12: +225967 [library] "launch: tmpdir=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsrtm8WB" #13: +267822 [library] "launch: umask=0002" #14: +269175 [library] "launch: euid=1000" #15: +289422 [trace] "get_backend_setting "force_tcg"" #16: +295737 [trace] "get_backend_setting = NULL (error)" #17: +305802 [trace] "get_cachedir" #18: +308463 [trace] "get_cachedir = "/home/kchamart/src/rwmj-fork-libguestfs/tmp"" #19: +328247 [library] "begin building supermin appliance" #20: +328915 [library] "run supermin" #21: +333007 [library] "command: run: /home/kchamart/src/supermin/src/supermin" #22: +333840 [library] "command: run: \ --build" #23: +334513 [library] "command: run: \ --verbose" #24: +335077 [library] "command: run: \ --if-newer" #25: +335822 [library] "command: run: \ --lock /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #26: +336975 [library] "command: run: \ --copy-kernel" #27: +337640 [library] "command: run: \ -f ext2" #28: +338520 [library] "command: run: \ --host-cpu x86_64" #29: +339113 [library] "command: run: \ /home/kchamart/src/rwmj-fork-libguestfs/appliance/supermin.d" #30: +339873 [library] "command: run: \ -o /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d" #31: +13295913 [appliance] "supermin: version: 5.1.15" #32: +13304953 [appliance] "supermin: rpm: detected RPM version 4.13" #33: +13305317 [appliance] "supermin: package handler: fedora/rpm" #34: +13305722 [appliance] "supermin: acquiring lock on /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #35: +13309156 [appliance] "supermin: if-newer: output does not need rebuilding" #36: +17927147 [library] "finished building supermin appliance" #37: +17977761 [library] "begin testing qemu features" #38: +17981977 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #39: +17983105 [library] "command: run: \ -display none" #40: +17983741 [library] "command: run: \ -help" #41: +108988991 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #42: +108991795 [library] "command: run: \ -display none" #43: +108993062 [library] "command: run: \ -version" #44: +197288120 [library] "qemu version 2.5" #45: +197293917 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #46: +197295377 [library] "command: run: \ -display none" #47: +197296363 [library] "command: run: \ -machine accel=kvm:tcg" #48: +197297181 [library] "command: run: \ -device ?" #49: +301438319 [trace] "get_sockdir" #50: +301448306 [trace] "get_sockdir = "/tmp"" #51: +301827417 [library] "finished testing qemu features" #52: +301846762 [trace] "get_backend_setting "gdb"" #53: +301854829 [trace] "get_backend_setting = NULL (error)" #54: +303906465 [appliance] "[00302ms] /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64 \" #55: +303908843 [appliance] " -global virtio-blk-pci.scsi=off \" #56: +303910403 [appliance] " -nodefconfig \" #57: +303911627 [appliance] " -enable-fips \" #58: +303912750 [appliance] " -nodefaults \" #59: +303914011 [appliance] " -display none \" #60: +303915214 [appliance] " -machine accel=kvm:tcg \" #61: +303916398 [appliance] " -cpu host \" #62: +303917565 [appliance] " -m 500 \" #63: +303918651 [appliance] " -no-reboot \" #64: +303919763 [appliance] " -rtc driftfix=slew \" #65: +303920871 [appliance] " -no-hpet \" #66: +303922055 [appliance] " -global kvm-pit.lost_tick_policy=discard \" #67: +303923298 [appliance] " -kernel /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/kernel \" #68: +303924614 [appliance] " -initrd /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/initrd \" #69: +303925861 [appliance] " -device virtio-scsi-pci,id=scsi \" #70: +303927140 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsrtm8WB/devnull1,cache=writeback,id=hd0,if=none \" #71: +303928320 [appliance] " -device scsi-hd,drive=hd0 \" #72: +303929614 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \" #73: +303930921 [appliance] " -device scsi-hd,drive=appliance \" #74: +303931997 [appliance] " -device virtio-serial-pci \" #75: +303933040 [appliance] " -serial stdio \" #76: +303934531 [appliance] " -device sga \" #77: +303935700 [appliance] " -chardev socket,path=/tmp/libguestfsnnIPbK/guestfsd.sock,id=channel0 \" #78: +303936944 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \" #79: +303938220 [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: +389784859 [appliance] "WARNING: Image format was not specified for '/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsrtm8WB/devnull1' and probing guessed raw." #81: +389788345 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted." #82: +389789628 [appliance] " Specify the 'raw' format explicitly to remove the restrictions." #83: +495997666 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n" #84: +498136250 [appliance] "Google, Inc." #85: +498137940 [appliance] "Serial Graphics Adapter 11/03/11" #86: +498139281 [appliance] "SGABIOS $Id$ (pbonzini@yakj.usersys.redhat.com) Thu Nov 3 13:33:51 UTC 2011" #87: +499232633 [appliance] "Term: 80x24" #88: +499234093 [appliance] "4 0" #89: +499235164 [appliance] "\x1b[2J\x0dSeaBIOS (version rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org)" #90: +564584532 [appliance] "\x0dBooting from ROM..." #91: +568930582 [appliance] "\x0dProbing EDD (edd=off to disable)... ok" #92: +568933647 [appliance] "\x1b[2J" #93: +741861583 [appliance] "[ 0.000000] Initializing cgroup subsys cpuset" #94: +741865170 [appliance] "[ 0.000000] Initializing cgroup subsys cpu" #95: +742964208 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct" #96: +742965812 [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: +745168689 [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: +747371495 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256" #99: +748470130 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'" #100: +749576966 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'" #101: +750679227 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'" #102: +750680825 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format." #103: +751773509 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches." #104: +752878078 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:" #105: +753984473 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable" #106: +753986065 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved" #107: +755086990 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved" #108: +756190884 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3ddfff] usable" #109: +757285040 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3de000-0x000000001f3fffff] reserved" #110: +758386619 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved" #111: +758388040 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved" #112: +759485551 [appliance] "[ 0.000000] NX (Execute Disable) protection: active" #113: +760587020 [appliance] "[ 0.000000] SMBIOS 2.8 present." #114: +760588483 [appliance] "[ 0.000000] Hypervisor detected: KVM" #115: +761683223 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3de max_arch_pfn = 0x400000000" #116: +761684822 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT " #117: +762788374 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f6bd0-0x000f6bdf] mapped at [ffff8800000f6bd0]" #118: +763889107 [appliance] "[ 0.000000] Scanning 1 areas for low memory corruption" #119: +764984947 [appliance] "[ 0.000000] Using GB pages for direct mapping" #120: +764986463 [appliance] "[ 0.000000] RAMDISK: [mem 0x00ee3000-0x00ffffff]" #121: +766080002 [appliance] "[ 0.000000] No NUMA configuration found" #122: +766081461 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3ddfff]" #123: +767175938 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f3cb000-0x1f3ddfff]" #124: +768268422 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00" #125: +768269772 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f3bb001, primary cpu clock" #126: +769373645 [appliance] "[ 0.000000] kvm-clock: using sched offset of 216775349 cycles" #127: +770477170 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns" #128: +771579012 [appliance] "[ 0.000000] Zone ranges:" #129: +771580436 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]" #130: +772684847 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3ddfff]" #131: +773778163 [appliance] "[ 0.000000] Normal empty" #132: +773779556 [appliance] "[ 0.000000] Movable zone start for each node" #133: +774890015 [appliance] "[ 0.000000] Early memory node ranges" #134: +774891525 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]" #135: +775994929 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3ddfff]" #136: +775996368 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3ddfff]" #137: +777100158 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org" #138: +778201150 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4" #139: +779294144 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU" #140: +779295574 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 " #141: +780387707 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000" #142: +780389076 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)" #143: +780390086 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23" #144: +781487032 [appliance] "[ 0.000000] Processors: 1" #145: +782591059 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs" #146: +782592515 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]" #147: +783689627 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]" #148: +784792146 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]" #149: +784793606 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]" #150: +785894861 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices" #151: +786995343 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM" #152: +786996699 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns" #153: +789195834 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1" #154: +790288103 [appliance] "[ 0.000000] PERCPU: Embedded 483 pages/cpu @ffff88001f000000 s1937944 r8192 d32232 u2097152" #155: +791381573 [appliance] "[ 0.000000] KVM setup async PF for cpu 0" #156: +791382906 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00db40" #157: +792478460 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125562" #158: +792479852 [appliance] "[ 0.000000] Policy zone: DMA32" #159: +793572754 [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: +795763342 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)" #161: +796863781 [appliance] "[ 0.000000] Memory: 463228K/511472K available (8747K kernel code, 1490K rwdata, 3660K rodata, 3536K init, 16580K bss, 48244K reserved, 0K cma-reserved)" #162: +797957735 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1" #163: +799062742 [appliance] "[ 0.000000] Running RCU self tests" #164: +800165030 [appliance] "[ 0.000000] Hierarchical RCU implementation." #165: +800166330 [appliance] "[ 0.000000] \x09RCU lockdep checking is enabled." #166: +801258596 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64." #167: +801259935 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1." #168: +802356204 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1" #169: +803455764 [appliance] "[ 0.000000] kmemleak: Kernel memory leak detector disabled" #170: +803456976 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16" #171: +804551762 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs" #172: +804552762 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0." #173: +805648272 [appliance] "[ 0.000000] Console: colour *CGA 80x25" #174: +805649378 [appliance] "[ 0.000000] console [ttyS0] enabled" #175: +806751249 [appliance] "[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar" #176: +807843903 [appliance] "[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8" #177: +807844939 [appliance] "[ 0.000000] ... MAX_LOCK_DEPTH: 48" #178: +808936064 [appliance] "[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191" #179: +808937157 [appliance] "[ 0.000000] ... CLASSHASH_SIZE: 4096" #180: +810029517 [appliance] "[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 32768" #181: +810030564 [appliance] "[ 0.000000] ... MAX_LOCKDEP_CHAINS: 65536" #182: +811123261 [appliance] "[ 0.000000] ... CHAINHASH_SIZE: 32768" #183: +811124382 [appliance] "[ 0.000000] memory used by lock dependency info: 8671 kB" #184: +812221368 [appliance] "[ 0.000000] per task-struct memory footprint: 2688 bytes" #185: +813308773 [appliance] "[ 0.000000] tsc: Detected 2099.998 MHz processor" #186: +814403805 [appliance] "[ 0.121835] Calibrating delay loop (skipped) preset value.. 4199.99 BogoMIPS (lpj=2099998)" #187: +815501130 [appliance] "[ 0.122945] pid_max: default: 32768 minimum: 301" #188: +815502140 [appliance] "[ 0.123650] Security Framework initialized" #189: +816601627 [appliance] "[ 0.124209] Yama: becoming mindful." #190: +816602646 [appliance] "[ 0.124686] SELinux: Disabled at boot." #191: +817695166 [appliance] "[ 0.125384] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)" #192: +818783524 [appliance] "[ 0.126463] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)" #193: +819886337 [appliance] "[ 0.127450] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)" #194: +820979045 [appliance] "[ 0.128329] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)" #195: +823193820 [appliance] "[ 0.130333] Initializing cgroup subsys io" #196: +823194937 [appliance] "[ 0.130905] Initializing cgroup subsys memory" #197: +824277538 [appliance] "[ 0.131798] Disabling memory control group subsystem" #198: +824278579 [appliance] "[ 0.132460] Initializing cgroup subsys devices" #199: +825377938 [appliance] "[ 0.133089] Initializing cgroup subsys freezer" #200: +826475025 [appliance] "[ 0.133699] Initializing cgroup subsys net_cls" #201: +826475997 [appliance] "[ 0.134297] Initializing cgroup subsys perf_event" #202: +827577986 [appliance] "[ 0.134938] Initializing cgroup subsys net_prio" #203: +827579092 [appliance] "[ 0.135537] Initializing cgroup subsys hugetlb" #204: +828673623 [appliance] "[ 0.136154] Initializing cgroup subsys pids" #205: +830538418 [appliance] "[ 0.137684] mce: CPU supports 10 MCE banks" #206: +830539498 [appliance] "[ 0.138310] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0" #207: +831637444 [appliance] "[ 0.139013] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0" #208: +848504374 [appliance] "[ 0.155648] Freeing SMP alternatives memory: 28K (ffffffff822ea000 - ffffffff822f1000)" #209: +853899944 [appliance] "[ 0.161053] ftrace: allocating 29768 entries in 117 pages" #210: +893473836 [appliance] "[ 0.200606] x2apic enabled" #211: +893475256 [appliance] "[ 0.201280] Switched APIC routing to physical x2apic." #212: +895937347 [appliance] "[ 0.203078] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1" #213: +895938681 [appliance] "[ 0.203870] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2620 v2 @ 2.10GHz (family: 0x6, model: 0x3e, stepping: 0x4)" #214: +897041320 [appliance] "[ 0.205276] Performance Events: 16-deep LBR, IvyBridge events, Intel PMU driver." #215: +899899095 [appliance] "[ 0.207285] ... version: 2" #216: +899900774 [appliance] "[ 0.207796] ... bit width: 48" #217: +901022520 [appliance] "[ 0.208379] ... generic registers: 4" #218: +901024236 [appliance] "[ 0.208891] ... value mask: 0000ffffffffffff" #219: +902131194 [appliance] "[ 0.209590] ... max period: 000000007fffffff" #220: +902133002 [appliance] "[ 0.210246] ... fixed-purpose events: 3" #221: +903292956 [appliance] "[ 0.210796] ... event mask: 000000070000000f" #222: +906081982 [appliance] "[ 0.213111] x86: Booted up 1 node, 1 CPUs" #223: +906083952 [appliance] "[ 0.213652] smpboot: Total of 1 processors activated (4199.99 BogoMIPS)" #224: +908808514 [appliance] "[ 0.215916] devtmpfs: initialized" #225: +912945407 [appliance] "[ 0.220029] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns" #226: +914048839 [appliance] "[ 0.221585] atomic64_test: passed for x86-64 platform with CX8 and with SSE" #227: +915155829 [appliance] "[ 0.222487] pinctrl core: initialized pinctrl subsystem" #228: +916290914 [appliance] "[ 0.223436] RTC time: 13:29:35, date: 03/21/16" #229: +916305288 [appliance] "[ 0.224461] NET: Registered protocol family 16" #230: +918693371 [appliance] "[ 0.225835] cpuidle: using governor menu" #231: +918695288 [appliance] "[ 0.226871] PCI: Using configuration type 1 for base access" #232: +919815941 [appliance] "[ 0.227978] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off" #233: +928821025 [appliance] "[ 0.235919] ACPI: Interpreter disabled." #234: +928822920 [appliance] "[ 0.236965] vgaarb: loaded" #235: +929919797 [appliance] "[ 0.237629] SCSI subsystem initialized" #236: +931260339 [appliance] "[ 0.238381] usbcore: registered new interface driver usbfs" #237: +931262112 [appliance] "[ 0.239120] usbcore: registered new interface driver hub" #238: +932377903 [appliance] "[ 0.239829] usbcore: registered new device driver usb" #239: +933641113 [appliance] "[ 0.240766] PCI: Probing PCI hardware" #240: +933642908 [appliance] "[ 0.241432] PCI host bridge to bus 0000:00" #241: +934755552 [appliance] "[ 0.241946] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]" #242: +934757075 [appliance] "[ 0.242730] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]" #243: +935866754 [appliance] "[ 0.243645] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]" #244: +946951515 [appliance] "[ 0.254025] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]" #245: +946954121 [appliance] "[ 0.254934] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]" #246: +948097230 [appliance] "[ 0.255811] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]" #247: +950235003 [appliance] "[ 0.257855] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]" #248: +951333780 [appliance] "[ 0.259511] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI" #249: +952450186 [appliance] "[ 0.260447] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB" #250: +1004551886 [appliance] "[ 0.311624] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]" #251: +1006271212 [appliance] "[ 0.313352] NetLabel: Initializing" #252: +1006272854 [appliance] "[ 0.313835] NetLabel: domain hash size = 128" #253: +1006273557 [appliance] "[ 0.314406] NetLabel: protocols = UNLABELED CIPSOv4" #254: +1007383899 [appliance] "[ 0.315108] NetLabel: unlabeled traffic allowed by default" #255: +1008473858 [appliance] "[ 0.316095] clocksource: Switched to clocksource kvm-clock" #256: +1051831757 [appliance] "[ 0.358888] pnp: PnP ACPI: disabled" #257: +1058649133 [appliance] "[ 0.365749] NET: Registered protocol family 2" #258: +1059941463 [appliance] "[ 0.367057] TCP established hash table entries: 4096 (order: 3, 32768 bytes)" #259: +1059943265 [appliance] "[ 0.368084] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)" #260: +1061043548 [appliance] "[ 0.369188] TCP: Hash tables configured (established 4096 bind 4096)" #261: +1062157658 [appliance] "[ 0.370079] UDP hash table entries: 256 (order: 3, 49152 bytes)" #262: +1063276636 [appliance] "[ 0.370904] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)" #263: +1064375405 [appliance] "[ 0.372107] NET: Registered protocol family 1" #264: +1065532770 [appliance] "[ 0.372707] pci 0000:00:00.0: Limiting direct PCI/PCI transfers" #265: +1065534229 [appliance] "[ 0.373502] pci 0000:00:01.0: PIIX3: Enabling Passive Release" #266: +1066648546 [appliance] "[ 0.374270] pci 0000:00:01.0: Activating ISA DMA hang workarounds" #267: +1067743212 [appliance] "[ 0.375459] Unpacking initramfs..." #268: +1071857891 [appliance] "[ 0.378925] Freeing initrd memory: 1140K (ffff880000ee3000 - ffff880001000000)" #269: +1091723763 [appliance] "[ 0.398759] DMA-API: preallocated 65536 debug entries" #270: +1091726589 [appliance] "[ 0.399537] DMA-API: debugging enabled by kernel config" #271: +1092891206 [appliance] "[ 0.400529] platform rtc_cmos: registered platform RTC device (no PNP device found)" #272: +1095095334 [appliance] "[ 0.402234] Scanning for low memory corruption every 60 seconds" #273: +1097190278 [appliance] "[ 0.404271] futex hash table entries: 256 (order: 3, 32768 bytes)" #274: +1097191941 [appliance] "[ 0.405164] audit: initializing netlink subsys (disabled)" #275: +1098313409 [appliance] "[ 0.405955] audit: type=2000 audit(1458566976.439:1): initialized" #276: +1099430846 [appliance] "[ 0.406989] cryptomgr_test (27) used greatest stack depth: 14040 bytes left" #277: +1101611686 [appliance] "[ 0.408754] Initialise system trusted keyring" #278: +1102764508 [appliance] "[ 0.409881] HugeTLB registered 1 GB page size, pre-allocated 0 pages" #279: +1102766124 [appliance] "[ 0.410761] HugeTLB registered 2 MB page size, pre-allocated 0 pages" #280: +1113444657 [appliance] "[ 0.420557] zbud: loaded" #281: +1114643643 [appliance] "[ 0.421720] VFS: Disk quotas dquot_6.6.0" #282: +1114645366 [appliance] "[ 0.422429] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)" #283: +1118582815 [appliance] "[ 0.425687] Key type big_key registered" #284: +1118584389 [appliance] "[ 0.426771] cryptomgr_test (35) used greatest stack depth: 13688 bytes left" #285: +1124648477 [appliance] "[ 0.431721] cryptomgr_test (53) used greatest stack depth: 13312 bytes left" #286: +1127364747 [appliance] "[ 0.434335] NET: Registered protocol family 38" #287: +1127366409 [appliance] "[ 0.434985] Key type asymmetric registered" #288: +1128511252 [appliance] "[ 0.435644] Asymmetric key parser 'x509' registered" #289: +1128512978 [appliance] "[ 0.436481] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)" #290: +1129617493 [appliance] "[ 0.437577] io scheduler noop registered" #291: +1130718846 [appliance] "[ 0.438150] io scheduler deadline registered" #292: +1130720300 [appliance] "[ 0.438826] io scheduler cfq registered (default)" #293: +1134690062 [appliance] "[ 0.441760] pci_hotplug: PCI Hot Plug PCI Core version: 0.5" #294: +1134691882 [appliance] "[ 0.442534] pciehp: PCI Express Hot Plug Controller Driver version: 0.4" #295: +1135786508 [appliance] "[ 0.443823] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled" #296: +1162226420 [appliance] "[ 0.469341] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A" #297: +1169785102 [appliance] "[ 0.476877] Non-volatile memory driver v1.3" #298: +1169786730 [appliance] "[ 0.477609] Linux agpgart interface v0.103" #299: +1174506859 [appliance] "[ 0.481609] scsi host0: ata_piix" #300: +1174508512 [appliance] "[ 0.482522] scsi host1: ata_piix" #301: +1175613703 [appliance] "[ 0.483153] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14" #302: +1176714820 [appliance] "[ 0.483999] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15" #303: +1178560523 [appliance] "[ 0.485662] libphy: Fixed MDIO Bus: probed" #304: +1178562083 [appliance] "[ 0.486432] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver" #305: +1179666647 [appliance] "[ 0.487297] ehci-pci: EHCI PCI platform driver" #306: +1180805775 [appliance] "[ 0.487927] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver" #307: +1180807524 [appliance] "[ 0.488731] ohci-pci: OHCI PCI platform driver" #308: +1181915004 [appliance] "[ 0.489353] uhci_hcd: USB Universal Host Controller Interface driver" #309: +1183013257 [appliance] "[ 0.490628] usbcore: registered new interface driver usbserial" #310: +1184112888 [appliance] "[ 0.491422] usbcore: registered new interface driver usbserial_generic" #311: +1185220498 [appliance] "[ 0.492353] usbserial: USB Serial support registered for generic" #312: +1185222197 [appliance] "[ 0.493188] i8042: PNP: No PS/2 controller found. Probing ports directly." #313: +1187924695 [appliance] "[ 0.495033] serio: i8042 KBD port at 0x60,0x64 irq 1" #314: +1187926321 [appliance] "[ 0.495769] serio: i8042 AUX port at 0x60,0x64 irq 12" #315: +1189010702 [appliance] "[ 0.497126] mousedev: PS/2 mouse device common for all mice" #316: +1191621913 [appliance] "[ 0.498729] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0" #317: +1195309359 [appliance] "[ 0.502390] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3" #318: +1196566519 [appliance] "[ 0.503691] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0" #319: +1196568178 [appliance] "[ 0.504617] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram" #320: +1197675613 [appliance] "[ 0.505653] device-mapper: uevent: version 1.0.3" #321: +1198766740 [appliance] "[ 0.506796] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2" #322: +1201343080 [appliance] "[ 0.508382] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com" #323: +1203151018 [appliance] "[ 0.510255] hidraw: raw HID events driver (C) Jiri Kosina" #324: +1203152634 [appliance] "[ 0.511124] usbcore: registered new interface driver usbhid" #325: +1204251011 [appliance] "[ 0.511822] usbhid: USB HID core driver" #326: +1205446849 [appliance] "[ 0.512582] drop_monitor: Initializing network drop monitor service" #327: +1205448437 [appliance] "[ 0.513635] ip_tables: (C) 2000-2006 Netfilter Core Team" #328: +1206563829 [appliance] "[ 0.514499] Initializing XFRM netlink socket" #329: +1208827995 [appliance] "[ 0.515955] NET: Registered protocol family 10" #330: +1210491820 [appliance] "[ 0.517599] mip6: Mobile IPv6" #331: +1210493347 [appliance] "[ 0.518027] NET: Registered protocol family 17" #332: +1212128759 [appliance] "[ 0.519227] microcode: CPU0 sig=0x306e4, pf=0x1, revision=0x1" #333: +1212130315 [appliance] "[ 0.520130] microcode: Microcode Update Driver: v2.01 , Peter Oruba" #334: +1213236255 [appliance] "[ 0.521290] AVX version of gcm_enc/dec engaged." #335: +1214347017 [appliance] "[ 0.521885] AES CTR mode by8 optimization enabled" #336: +1216314691 [appliance] "[ 0.523415] cryptomgr_test (85) used greatest stack depth: 13224 bytes left" #337: +1243734104 [appliance] "[ 0.550822] registered taskstats version 1" #338: +1243735599 [appliance] "[ 0.551421] Loading compiled-in X.509 certificates" #339: +1246037121 [appliance] "[ 0.553161] Loaded X.509 cert 'Fedora kernel signing key: d33a3fa294f19598ff71e1ac24c3cdc70d17052c'" #340: +1247217026 [appliance] "[ 0.554354] cryptomgr_test (100) used greatest stack depth: 12696 bytes left" #341: +1247247546 [appliance] "[ 0.555438] zswap: loaded using pool lzo/zbud" #342: +1250357407 [appliance] "[ 0.557458] Magic number: 8:862:483" #343: +1250358849 [appliance] "[ 0.558071] rtc_cmos rtc_cmos: setting system clock to 2016-03-21 13:29:35 UTC (1458566975)" #344: +1337407037 [appliance] "[ 0.644456] Freeing unused kernel memory: 3536K (ffffffff81f76000 - ffffffff822ea000)" #345: +1337411174 [appliance] "[ 0.645512] Write protecting the kernel read-only data: 14336k" #346: +1340682204 [appliance] "[ 0.647781] Freeing unused kernel memory: 1480K (ffff88000188e000 - ffff880001a00000)" #347: +1343001267 [appliance] "[ 0.650112] Freeing unused kernel memory: 436K (ffff880001d93000 - ffff880001e00000)" #348: +1344980153 [appliance] "supermin: mounting /proc" #349: +1344981495 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 glibc" #350: +1346305177 [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: +1347415726 [appliance] "supermin: uptime: 0.46 0.13" #352: +1348613229 [appliance] "supermin: mounting /sys" #353: +1348614579 [appliance] "supermin: internal insmod crc32-pclmul.ko" #354: +1351506280 [appliance] "supermin: internal insmod crc32c-intel.ko" #355: +1353615908 [appliance] "supermin: internal insmod crct10dif-pclmul.ko" #356: +1355572092 [appliance] "supermin: internal insmod crc32.ko" #357: +1357421916 [appliance] "supermin: internal insmod virtio.ko" #358: +1359303945 [appliance] "supermin: internal insmod virtio_ring.ko" #359: +1361197876 [appliance] "supermin: internal insmod virtio_blk.ko" #360: +1363304846 [appliance] "supermin: internal insmod virtio-rng.ko" #361: +1365173999 [appliance] "supermin: internal insmod virtio_console.ko" #362: +1367480973 [appliance] "supermin: internal insmod virtio_net.ko" #363: +1369816627 [appliance] "supermin: internal insmod virtio_scsi.ko" #364: +1371985982 [appliance] "supermin: internal insmod virtio_balloon.ko" #365: +1373894310 [appliance] "supermin: internal insmod virtio_input.ko" #366: +1375729347 [appliance] "supermin: internal insmod virtio_mmio.ko" #367: +1377666993 [appliance] "supermin: internal insmod virtio_pci.ko" #368: +1380310056 [appliance] "[ 0.687404] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10" #369: +1380311460 [appliance] "[ 0.688414] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver" #370: +1383821422 [appliance] "[ 0.690931] scsi host2: Virtio SCSI HBA" #371: +1385429371 [appliance] "[ 0.692517] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11" #372: +1385430828 [appliance] "[ 0.693581] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver" #373: +1430232001 [appliance] "[ 0.737278] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #374: +1432947366 [appliance] "[ 0.740005] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #375: +1572135995 [appliance] "[ 0.877506] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)" #376: +1573755341 [appliance] "[ 0.880871] sd 2:0:0:0: Attached scsi generic sg0 type 0" #377: +1575712455 [appliance] "[ 0.882815] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)" #378: +1577043210 [appliance] "[ 0.884168] sd 2:0:1:0: [sdb] Write Protect is off" #379: +1577044678 [appliance] "[ 0.884830] sd 2:0:0:0: [sda] Write Protect is off" #380: +1578176430 [appliance] "[ 0.885704] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #381: +1580469021 [appliance] "[ 0.888280] sd 2:0:1:0: Attached scsi generic sg1 type 0" #382: +1583199865 [appliance] "[ 0.890232] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #383: +1591105299 [appliance] "[ 0.898181] Dev sda: unable to read RDB block 8" #384: +1591107059 [appliance] "[ 0.898907] sda: unable to read partition table" #385: +1592228074 [appliance] "[ 0.899673] sda: partition table beyond EOD, enabling native capacity" #386: +1593316600 [appliance] "[ 0.901455] sd 2:0:1:0: [sdb] Attached SCSI disk" #387: +1596258775 [appliance] "[ 0.903342] Dev sda: unable to read RDB block 8" #388: +1596260627 [appliance] "[ 0.904056] sda: unable to read partition table" #389: +1597380948 [appliance] "[ 0.904808] sda: partition table beyond EOD, truncated" #390: +1599647007 [appliance] "[ 0.906735] sd 2:0:0:0: [sda] Attached SCSI disk" #391: +1599648586 [appliance] "supermin: internal insmod crc-ccitt.ko" #392: +1602259884 [appliance] "supermin: internal insmod crc-itu-t.ko" #393: +1604147740 [appliance] "supermin: internal insmod crc8.ko" #394: +1605898169 [appliance] "supermin: internal insmod libcrc32c.ko" #395: +1608276052 [appliance] "supermin: picked /sys/block/sdb/dev as root device" #396: +1609548369 [appliance] "supermin: creating /dev/root as block special 8:16" #397: +1609549929 [appliance] "supermin: mounting new root on /root" #398: +1611825601 [appliance] "[ 0.918918] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem" #399: +1634190844 [appliance] "[ 0.941280] EXT4-fs (sdb): mounted filesystem without journal. Opts: " #400: +1634193378 [appliance] "supermin: chroot" #401: +1668697527 [appliance] "Starting /init script ..." #402: +1798025346 [appliance] "[ 1.105080] ldconfig (378) used greatest stack depth: 11392 bytes left" #403: +1845415820 [appliance] "[ 1.152514] random: systemd-tmpfile urandom read with 68 bits of entropy available" #404: +1848054802 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m" #405: +1850825896 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m" #406: +1850827373 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m" #407: +1851932937 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m" #408: +1853047560 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m" #409: +1854168865 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:34] Failed to replace specifiers: /var/log/journal/%m" #410: +1855269123 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:35] Failed to replace specifiers: /var/log/journal/%m" #411: +1858655760 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd" #412: +1863942796 [appliance] "starting version 222" #413: +2001928480 [appliance] "[ 1.308903] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9" #414: +2015370693 [appliance] "[ 1.322460] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0" #415: +2096152919 [appliance] "[ 1.403195] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e452ea631d, max_idle_ns: 440795244572 ns" #416: +2105951480 [appliance] "[ 1.413037] random: nonblocking pool is initialized" #417: +2241704530 [appliance] "[ 1.548740] input: PC Speaker as /devices/platform/pcspkr/input/input4" #418: +2297241528 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline" #419: +2301172342 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline" #420: +2306995685 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline" #421: +2312830140 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline" #422: +2315612628 [appliance] "+ guestfs_boot_analysis=1" #423: +2315614030 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline" #424: +2318670993 [appliance] "+ eval" #425: +2318672158 [appliance] "+ grep -sq selinux=1 /proc/cmdline" #426: +2321276341 [appliance] "+ shopt -s nullglob" #427: +2321277735 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #428: +2322421100 [appliance] "+ echo 300" #429: +2322422231 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #430: +2323512402 [appliance] "+ echo 300" #431: +2323513799 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #432: +2324597675 [appliance] "+ echo noop" #433: +2326174295 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #434: +2326175652 [appliance] "+ echo noop" #435: +2326175999 [appliance] "+ shopt -u nullglob" #436: +2327268312 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host" #437: +2332282140 [appliance] "+ ip link set dev lo up" #438: +2335112567 [appliance] "+ test '' = 1" #439: +2335113927 [appliance] "+ mdadm -As --auto=yes --run" #440: +2345670617 [appliance] "mdadm: No arrays found in config file or automatically" #441: +2345672152 [appliance] "+ modprobe dm_mod" #442: +2349746568 [appliance] "+ lvmetad" #443: +2358732562 [appliance] "+ lvm vgchange -aay --sysinit" #444: +2370297727 [appliance] " lvmetad is not active yet, using direct activation during sysinit" #445: +2376813364 [appliance] "+ ldmtool create all" #446: +2386742116 [appliance] "[" #447: +2386744076 [appliance] "]" #448: +2389055565 [appliance] "+ test 1 = 1" #449: +2389056931 [appliance] "+ test 1 '!=' 1" #450: +2389057314 [appliance] "+ test '' = 1" #451: +2389057599 [appliance] "+ cmd=guestfsd" #452: +2390228149 [appliance] "+ test x '!=' x" #453: +2390229247 [appliance] "+ test 1 = 1" #454: +2390229581 [appliance] "+ cmd='guestfsd --verbose'" #455: +2390229780 [appliance] "+ test '' = 1" #456: +2391334390 [appliance] "+ echo guestfsd --verbose" #457: +2391335520 [appliance] "guestfsd --verbose" #458: +2391335778 [appliance] "+ guestfsd --verbose" #459: +2410895706 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'" #460: +2410897706 [appliance] "udevadm --debug settle" #461: +2417273183 [appliance] "calling: settle" #462: +2417516382 [launch_done] "launch done callback" #463: +2417542448 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG" #464: +2417544293 [library] "appliance is up" #465: +2417568426 [trace] "launch = 0" #466: +2417570902 [trace] "close" #467: +2417572249 [library] "closing guestfs handle 0xe417a0 (state 2)" #468: +2417575966 [trace] "internal_autosync" #469: +2421432758 [appliance] "guestfsd: main_loop: new request, len 0x28" #470: +2421434325 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0" #471: +2422551894 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0" #472: +2423667359 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0" #473: +2424789322 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=93972k,mode=755 freq=0 passno=0" #474: +2425938157 [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" #475: +2432943373 [appliance] "fsync /dev/sda" #476: +2432944777 [appliance] "guestfsd: main_loop: proc 282 (internal_autosync) took 0.01 seconds" #477: +2434032941 [trace] "internal_autosync = 0" #478: +2434036249 [library] "sending SIGTERM to process 38598" #479: +2448784732 [close] "close callback" #480: +2448808147 [library] "command: run: rm" #481: +2448809677 [library] "command: run: \ -rf /home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsrtm8WB" #482: +2450682045 [library] "command: run: rm" #483: +2450683302 [library] "command: run: \ -rf /tmp/libguestfsnnIPbK" pass 1 number of events collected 484 elapsed time 2446303944 ns #0: +162660 [trace] "launch" #1: +164820 [trace] "version" #2: +168673 [trace] "version = " #3: +170380 [trace] "get_backend" #4: +172190 [trace] "get_backend = "direct"" #5: +173568 [library] "launch: program=boot-analysis" #6: +174640 [library] "launch: version=1.33.15" #7: +175338 [library] "launch: backend registered: unix" #8: +175896 [library] "launch: backend registered: uml" #9: +176471 [library] "launch: backend registered: libvirt" #10: +176981 [library] "launch: backend registered: direct" #11: +177750 [library] "launch: backend=direct" #12: +178347 [library] "launch: tmpdir=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsPGhdmX" #13: +226186 [library] "launch: umask=0002" #14: +227363 [library] "launch: euid=1000" #15: +241020 [trace] "get_backend_setting "force_tcg"" #16: +246963 [trace] "get_backend_setting = NULL (error)" #17: +255533 [trace] "get_cachedir" #18: +257830 [trace] "get_cachedir = "/home/kchamart/src/rwmj-fork-libguestfs/tmp"" #19: +272546 [library] "begin building supermin appliance" #20: +273531 [library] "run supermin" #21: +276618 [library] "command: run: /home/kchamart/src/supermin/src/supermin" #22: +277426 [library] "command: run: \ --build" #23: +278004 [library] "command: run: \ --verbose" #24: +278516 [library] "command: run: \ --if-newer" #25: +279177 [library] "command: run: \ --lock /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #26: +279743 [library] "command: run: \ --copy-kernel" #27: +280316 [library] "command: run: \ -f ext2" #28: +281373 [library] "command: run: \ --host-cpu x86_64" #29: +282097 [library] "command: run: \ /home/kchamart/src/rwmj-fork-libguestfs/appliance/supermin.d" #30: +282831 [library] "command: run: \ -o /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d" #31: +12137922 [appliance] "supermin: version: 5.1.15" #32: +12139838 [appliance] "supermin: rpm: detected RPM version 4.13" #33: +12140307 [appliance] "supermin: package handler: fedora/rpm" #34: +12140772 [appliance] "supermin: acquiring lock on /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/lock" #35: +12141334 [appliance] "supermin: if-newer: output does not need rebuilding" #36: +15355294 [library] "finished building supermin appliance" #37: +15384395 [library] "begin testing qemu features" #38: +15389082 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #39: +15390101 [library] "command: run: \ -display none" #40: +15390734 [library] "command: run: \ -help" #41: +100634918 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #42: +100637523 [library] "command: run: \ -display none" #43: +100638500 [library] "command: run: \ -version" #44: +193044921 [library] "qemu version 2.5" #45: +193056403 [library] "command: run: /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64" #46: +193058472 [library] "command: run: \ -display none" #47: +193060275 [library] "command: run: \ -machine accel=kvm:tcg" #48: +193063306 [library] "command: run: \ -device ?" #49: +282628176 [trace] "get_sockdir" #50: +282637778 [trace] "get_sockdir = "/tmp"" #51: +282809669 [library] "finished testing qemu features" #52: +282833591 [trace] "get_backend_setting "gdb"" #53: +282841416 [trace] "get_backend_setting = NULL (error)" #54: +285151901 [appliance] "[00284ms] /home/kchamart/build/qemu-build/x86_64-softmmu/qemu-system-x86_64 \" #55: +285154139 [appliance] " -global virtio-blk-pci.scsi=off \" #56: +285155386 [appliance] " -nodefconfig \" #57: +285156044 [appliance] " -enable-fips \" #58: +285156821 [appliance] " -nodefaults \" #59: +285157468 [appliance] " -display none \" #60: +285158086 [appliance] " -machine accel=kvm:tcg \" #61: +285158819 [appliance] " -cpu host \" #62: +285159506 [appliance] " -m 500 \" #63: +285160145 [appliance] " -no-reboot \" #64: +285160777 [appliance] " -rtc driftfix=slew \" #65: +285161356 [appliance] " -no-hpet \" #66: +285162000 [appliance] " -global kvm-pit.lost_tick_policy=discard \" #67: +285162718 [appliance] " -kernel /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/kernel \" #68: +285163556 [appliance] " -initrd /home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/initrd \" #69: +285164265 [appliance] " -device virtio-scsi-pci,id=scsi \" #70: +285164990 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsPGhdmX/devnull1,cache=writeback,id=hd0,if=none \" #71: +285166063 [appliance] " -device scsi-hd,drive=hd0 \" #72: +285166979 [appliance] " -drive file=/home/kchamart/src/rwmj-fork-libguestfs/tmp/.guestfs-1000/appliance.d/root,snapshot=on,id=appliance,cache=unsafe,if=none \" #73: +285167750 [appliance] " -device scsi-hd,drive=appliance \" #74: +285168383 [appliance] " -device virtio-serial-pci \" #75: +285168952 [appliance] " -serial stdio \" #76: +285169537 [appliance] " -device sga \" #77: +285170179 [appliance] " -chardev socket,path=/tmp/libguestfs106Kab/guestfsd.sock,id=channel0 \" #78: +285170990 [appliance] " -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 \" #79: +285171874 [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: +370321077 [appliance] "WARNING: Image format was not specified for '/home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsPGhdmX/devnull1' and probing guessed raw." #81: +370323517 [appliance] " Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted." #82: +370324359 [appliance] " Specify the 'raw' format explicitly to remove the restrictions." #83: +473558149 [appliance] "\x1b[1;256r\x1b[256;256H\x1b[6n" #84: +475577194 [appliance] "Google, Inc." #85: +475578124 [appliance] "Serial Graphics Adapter 11/03/11" #86: +475578692 [appliance] "SGABIOS $Id$ (pbonzini@yakj.usersys.redhat.com) Thu Nov 3 13:33:51 UTC 2011" #87: +476654639 [appliance] "Term: 80x24" #88: +476655234 [appliance] "4 0" #89: +476655639 [appliance] "\x1b[2J\x0dSeaBIOS (version rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org)" #90: +540871135 [appliance] "\x0dBooting from ROM..." #91: +545202817 [appliance] "\x0dProbing EDD (edd=off to disable)... ok" #92: +545204930 [appliance] "\x1b[2J" #93: +714690069 [appliance] "[ 0.000000] Initializing cgroup subsys cpuset" #94: +714693242 [appliance] "[ 0.000000] Initializing cgroup subsys cpu" #95: +715788081 [appliance] "[ 0.000000] Initializing cgroup subsys cpuacct" #96: +715788863 [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: +717984991 [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: +721295175 [appliance] "[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256" #99: +721296062 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x01: 'x87 floating point registers'" #100: +722398477 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x02: 'SSE registers'" #101: +723495797 [appliance] "[ 0.000000] x86/fpu: Supporting XSAVE feature 0x04: 'AVX registers'" #102: +724597634 [appliance] "[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format." #103: +725699670 [appliance] "[ 0.000000] x86/fpu: Using 'eager' FPU context switches." #104: +726791070 [appliance] "[ 0.000000] e820: BIOS-provided physical RAM map:" #105: +726791740 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009f7ff] usable" #106: +727892899 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000000009f800-0x000000000009ffff] reserved" #107: +728987711 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved" #108: +730090126 [appliance] "[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000001f3ddfff] usable" #109: +730093498 [appliance] "[ 0.000000] BIOS-e820: [mem 0x000000001f3de000-0x000000001f3fffff] reserved" #110: +731187705 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved" #111: +732296140 [appliance] "[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved" #112: +733400053 [appliance] "[ 0.000000] NX (Execute Disable) protection: active" #113: +733400686 [appliance] "[ 0.000000] SMBIOS 2.8 present." #114: +734497032 [appliance] "[ 0.000000] Hypervisor detected: KVM" #115: +734497711 [appliance] "[ 0.000000] e820: last_pfn = 0x1f3de max_arch_pfn = 0x400000000" #116: +735588523 [appliance] "[ 0.000000] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WC UC- WT " #117: +736690199 [appliance] "[ 0.000000] found SMP MP-table at [mem 0x000f6bd0-0x000f6bdf] mapped at [ffff8800000f6bd0]" #118: +737786741 [appliance] "[ 0.000000] Scanning 1 areas for low memory corruption" #119: +737787321 [appliance] "[ 0.000000] Using GB pages for direct mapping" #120: +738889966 [appliance] "[ 0.000000] RAMDISK: [mem 0x00ee3000-0x00ffffff]" #121: +739990785 [appliance] "[ 0.000000] No NUMA configuration found" #122: +739991476 [appliance] "[ 0.000000] Faking a node at [mem 0x0000000000000000-0x000000001f3ddfff]" #123: +741084005 [appliance] "[ 0.000000] NODE_DATA(0) allocated [mem 0x1f3cb000-0x1f3ddfff]" #124: +742186916 [appliance] "[ 0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00" #125: +742187521 [appliance] "[ 0.000000] kvm-clock: cpu 0, msr 0:1f3bb001, primary cpu clock" #126: +743281158 [appliance] "[ 0.000000] kvm-clock: using sched offset of 211168853 cycles" #127: +744379438 [appliance] "[ 0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns" #128: +745474691 [appliance] "[ 0.000000] Zone ranges:" #129: +745475431 [appliance] "[ 0.000000] DMA [mem 0x0000000000001000-0x0000000000ffffff]" #130: +746574025 [appliance] "[ 0.000000] DMA32 [mem 0x0000000001000000-0x000000001f3ddfff]" #131: +747679285 [appliance] "[ 0.000000] Normal empty" #132: +747679980 [appliance] "[ 0.000000] Movable zone start for each node" #133: +748781476 [appliance] "[ 0.000000] Early memory node ranges" #134: +748782146 [appliance] "[ 0.000000] node 0: [mem 0x0000000000001000-0x000000000009efff]" #135: +749878085 [appliance] "[ 0.000000] node 0: [mem 0x0000000000100000-0x000000001f3ddfff]" #136: +750997290 [appliance] "[ 0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000001f3ddfff]" #137: +750998078 [appliance] "[ 0.000000] SFI: Simple Firmware Interface v0.81 http://simplefirmware.org" #138: +752101017 [appliance] "[ 0.000000] Intel MultiProcessor Specification v1.4" #139: +753201271 [appliance] "[ 0.000000] MPTABLE: OEM ID: BOCHSCPU" #140: +753201896 [appliance] "[ 0.000000] MPTABLE: Product ID: 0.1 " #141: +754299217 [appliance] "[ 0.000000] MPTABLE: APIC at: 0xFEE00000" #142: +754299877 [appliance] "[ 0.000000] Processor #0 (Bootup-CPU)" #143: +755393017 [appliance] "[ 0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23" #144: +756501932 [appliance] "[ 0.000000] Processors: 1" #145: +756502661 [appliance] "[ 0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs" #146: +756503051 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x00000000-0x00000fff]" #147: +757604114 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x0009f000-0x0009ffff]" #148: +758701794 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000effff]" #149: +759801345 [appliance] "[ 0.000000] PM: Registered nosave memory: [mem 0x000f0000-0x000fffff]" #150: +760899944 [appliance] "[ 0.000000] e820: [mem 0x1f400000-0xfeffbfff] available for PCI devices" #151: +760900513 [appliance] "[ 0.000000] Booting paravirtualized kernel on KVM" #152: +761992252 [appliance] "[ 0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns" #153: +763091842 [appliance] "[ 0.000000] setup_percpu: NR_CPUS:1024 nr_cpumask_bits:1 nr_cpu_ids:1 nr_node_ids:1" #154: +764195874 [appliance] "[ 0.000000] PERCPU: Embedded 483 pages/cpu @ffff88001f000000 s1937944 r8192 d32232 u2097152" #155: +765296872 [appliance] "[ 0.000000] KVM setup async PF for cpu 0" #156: +766390132 [appliance] "[ 0.000000] kvm-stealtime: cpu 0, msr 1f00db40" #157: +766390801 [appliance] "[ 0.000000] Built 1 zonelists in Node order, mobility grouping on. Total pages: 125562" #158: +767498564 [appliance] "[ 0.000000] Policy zone: DMA32" #159: +767499197 [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: +770787917 [appliance] "[ 0.000000] PID hash table entries: 2048 (order: 2, 16384 bytes)" #161: +771878653 [appliance] "[ 0.000000] Memory: 463228K/511472K available (8747K kernel code, 1490K rwdata, 3660K rodata, 3536K init, 16580K bss, 48244K reserved, 0K cma-reserved)" #162: +772979324 [appliance] "[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1" #163: +774082355 [appliance] "[ 0.000000] Running RCU self tests" #164: +774082970 [appliance] "[ 0.000000] Hierarchical RCU implementation." #165: +775178930 [appliance] "[ 0.000000] \x09RCU lockdep checking is enabled." #166: +775193589 [appliance] "[ 0.000000] \x09Build-time adjustment of leaf fanout to 64." #167: +776298696 [appliance] "[ 0.000000] \x09RCU restricting CPUs from NR_CPUS=1024 to nr_cpu_ids=1." #168: +777394513 [appliance] "[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1" #169: +778499172 [appliance] "[ 0.000000] kmemleak: Kernel memory leak detector disabled" #170: +778500249 [appliance] "[ 0.000000] NR_IRQS:65792 nr_irqs:256 16" #171: +779600016 [appliance] "[ 0.000000] \x09Offload RCU callbacks from all CPUs" #172: +779600952 [appliance] "[ 0.000000] \x09Offload RCU callbacks from CPUs: 0." #173: +780691951 [appliance] "[ 0.000000] Console: colour *CGA 80x25" #174: +780692950 [appliance] "[ 0.000000] console [ttyS0] enabled" #175: +781785775 [appliance] "[ 0.000000] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar" #176: +782886951 [appliance] "[ 0.000000] ... MAX_LOCKDEP_SUBCLASSES: 8" #177: +782887935 [appliance] "[ 0.000000] ... MAX_LOCK_DEPTH: 48" #178: +783987850 [appliance] "[ 0.000000] ... MAX_LOCKDEP_KEYS: 8191" #179: +783988838 [appliance] "[ 0.000000] ... CLASSHASH_SIZE: 4096" #180: +785087063 [appliance] "[ 0.000000] ... MAX_LOCKDEP_ENTRIES: 32768" #181: +785088095 [appliance] "[ 0.000000] ... MAX_LOCKDEP_CHAINS: 65536" #182: +786181634 [appliance] "[ 0.000000] ... CHAINHASH_SIZE: 32768" #183: +786182555 [appliance] "[ 0.000000] memory used by lock dependency info: 8671 kB" #184: +787281924 [appliance] "[ 0.000000] per task-struct memory footprint: 2688 bytes" #185: +788356470 [appliance] "[ 0.000000] tsc: Detected 2099.998 MHz processor" #186: +789450215 [appliance] "[ 0.124882] Calibrating delay loop (skipped) preset value.. 4199.99 BogoMIPS (lpj=2099998)" #187: +790552644 [appliance] "[ 0.126025] pid_max: default: 32768 minimum: 301" #188: +791676453 [appliance] "[ 0.126750] Security Framework initialized" #189: +791677466 [appliance] "[ 0.127327] Yama: becoming mindful." #190: +791678198 [appliance] "[ 0.127830] SELinux: Disabled at boot." #191: +792769314 [appliance] "[ 0.128547] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes)" #192: +793857738 [appliance] "[ 0.129658] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes)" #193: +794967476 [appliance] "[ 0.130665] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes)" #194: +796071589 [appliance] "[ 0.131571] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes)" #195: +798554806 [appliance] "[ 0.133626] Initializing cgroup subsys io" #196: +798555995 [appliance] "[ 0.134237] Initializing cgroup subsys memory" #197: +799637788 [appliance] "[ 0.135168] Disabling memory control group subsystem" #198: +800755536 [appliance] "[ 0.135843] Initializing cgroup subsys devices" #199: +800756566 [appliance] "[ 0.136476] Initializing cgroup subsys freezer" #200: +801851662 [appliance] "[ 0.137133] Initializing cgroup subsys net_cls" #201: +801852611 [appliance] "[ 0.137749] Initializing cgroup subsys perf_event" #202: +802938584 [appliance] "[ 0.138402] Initializing cgroup subsys net_prio" #203: +802939602 [appliance] "[ 0.139054] Initializing cgroup subsys hugetlb" #204: +804039899 [appliance] "[ 0.139676] Initializing cgroup subsys pids" #205: +806190911 [appliance] "[ 0.141264] mce: CPU supports 10 MCE banks" #206: +806192181 [appliance] "[ 0.141898] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0" #207: +807287913 [appliance] "[ 0.142618] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0" #208: +824272753 [appliance] "[ 0.159348] Freeing SMP alternatives memory: 28K (ffffffff822ea000 - ffffffff822f1000)" #209: +829723090 [appliance] "[ 0.164809] ftrace: allocating 29768 entries in 117 pages" #210: +868811832 [appliance] "[ 0.203875] x2apic enabled" #211: +868813176 [appliance] "[ 0.204544] Switched APIC routing to physical x2apic." #212: +871292651 [appliance] "[ 0.206371] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1" #213: +871293773 [appliance] "[ 0.207211] smpboot: CPU0: Intel(R) Xeon(R) CPU E5-2620 v2 @ 2.10GHz (family: 0x6, model: 0x3e, stepping: 0x4)" #214: +873531579 [appliance] "[ 0.208603] Performance Events: 16-deep LBR, IvyBridge events, Intel PMU driver." #215: +873532825 [appliance] "[ 0.209674] ... version: 2" #216: +874631614 [appliance] "[ 0.210209] ... bit width: 48" #217: +874632656 [appliance] "[ 0.210757] ... generic registers: 4" #218: +875732162 [appliance] "[ 0.211286] ... value mask: 0000ffffffffffff" #219: +876828987 [appliance] "[ 0.211986] ... max period: 000000007fffffff" #220: +876829959 [appliance] "[ 0.212676] ... fixed-purpose events: 3" #221: +877919041 [appliance] "[ 0.213214] ... event mask: 000000070000000f" #222: +880534698 [appliance] "[ 0.215599] x86: Booted up 1 node, 1 CPUs" #223: +880535771 [appliance] "[ 0.216151] smpboot: Total of 1 processors activated (4199.99 BogoMIPS)" #224: +883297267 [appliance] "[ 0.218385] devtmpfs: initialized" #225: +887130615 [appliance] "[ 0.222203] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns" #226: +888227734 [appliance] "[ 0.223745] atomic64_test: passed for x86-64 platform with CX8 and with SSE" #227: +889312249 [appliance] "[ 0.224656] pinctrl core: initialized pinctrl subsystem" #228: +890543450 [appliance] "[ 0.225631] RTC time: 13:29:38, date: 03/21/16" #229: +890544508 [appliance] "[ 0.226684] NET: Registered protocol family 16" #230: +892942659 [appliance] "[ 0.228034] cpuidle: using governor menu" #231: +892943668 [appliance] "[ 0.229081] PCI: Using configuration type 1 for base access" #232: +894031981 [appliance] "[ 0.230194] perf_event_intel: PMU erratum BJ122, BV98, HSD29 workaround disabled, HT off" #233: +903098264 [appliance] "[ 0.238185] ACPI: Interpreter disabled." #234: +903099221 [appliance] "[ 0.239215] vgaarb: loaded" #235: +904190086 [appliance] "[ 0.239888] SCSI subsystem initialized" #236: +905570595 [appliance] "[ 0.240644] usbcore: registered new interface driver usbfs" #237: +905571868 [appliance] "[ 0.241408] usbcore: registered new interface driver hub" #238: +906665894 [appliance] "[ 0.242139] usbcore: registered new device driver usb" #239: +907999333 [appliance] "[ 0.243078] PCI: Probing PCI hardware" #240: +908000323 [appliance] "[ 0.243747] PCI host bridge to bus 0000:00" #241: +909098504 [appliance] "[ 0.244303] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]" #242: +909099531 [appliance] "[ 0.245115] pci_bus 0000:00: root bus resource [mem 0x00000000-0xffffffffff]" #243: +910192201 [appliance] "[ 0.246048] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]" #244: +928509178 [appliance] "[ 0.263575] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]" #245: +928510485 [appliance] "[ 0.264516] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]" #246: +929617743 [appliance] "[ 0.265374] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]" #247: +930718627 [appliance] "[ 0.266316] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]" #248: +931798585 [appliance] "[ 0.267897] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI" #249: +932888124 [appliance] "[ 0.268854] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB" #250: +987440954 [appliance] "[ 0.322471] pci 0000:00:01.0: PIIX/ICH IRQ router [8086:7000]" #251: +989249625 [appliance] "[ 0.324273] NetLabel: Initializing" #252: +989251439 [appliance] "[ 0.324775] NetLabel: domain hash size = 128" #253: +989252239 [appliance] "[ 0.325323] NetLabel: protocols = UNLABELED CIPSOv4" #254: +990358982 [appliance] "[ 0.326052] NetLabel: unlabeled traffic allowed by default" #255: +991462331 [appliance] "[ 0.327029] clocksource: Switched to clocksource kvm-clock" #256: +1034389512 [appliance] "[ 0.369340] pnp: PnP ACPI: disabled" #257: +1041427505 [appliance] "[ 0.376469] NET: Registered protocol family 2" #258: +1042714684 [appliance] "[ 0.377777] TCP established hash table entries: 4096 (order: 3, 32768 bytes)" #259: +1042716603 [appliance] "[ 0.378852] TCP bind hash table entries: 4096 (order: 6, 327680 bytes)" #260: +1043823859 [appliance] "[ 0.379914] TCP: Hash tables configured (established 4096 bind 4096)" #261: +1044922934 [appliance] "[ 0.380996] UDP hash table entries: 256 (order: 3, 49152 bytes)" #262: +1046038237 [appliance] "[ 0.381823] UDP-Lite hash table entries: 256 (order: 3, 49152 bytes)" #263: +1047151482 [appliance] "[ 0.382869] NET: Registered protocol family 1" #264: +1048265055 [appliance] "[ 0.383478] pci 0000:00:00.0: Limiting direct PCI/PCI transfers" #265: +1048266649 [appliance] "[ 0.384286] pci 0000:00:01.0: PIIX3: Enabling Passive Release" #266: +1049381408 [appliance] "[ 0.385071] pci 0000:00:01.0: Activating ISA DMA hang workarounds" #267: +1050485363 [appliance] "[ 0.386284] Unpacking initramfs..." #268: +1054801525 [appliance] "[ 0.389834] Freeing initrd memory: 1140K (ffff880000ee3000 - ffff880001000000)" #269: +1074361638 [appliance] "[ 0.409341] DMA-API: preallocated 65536 debug entries" #270: +1074364042 [appliance] "[ 0.410072] DMA-API: debugging enabled by kernel config" #271: +1075466643 [appliance] "[ 0.411095] platform rtc_cmos: registered platform RTC device (no PNP device found)" #272: +1078495150 [appliance] "[ 0.413530] Scanning for low memory corruption every 60 seconds" #273: +1080550705 [appliance] "[ 0.415574] futex hash table entries: 256 (order: 3, 32768 bytes)" #274: +1080552566 [appliance] "[ 0.416448] audit: initializing netlink subsys (disabled)" #275: +1081619143 [appliance] "[ 0.417262] audit: type=2000 audit(1458566978.867:1): initialized" #276: +1082709853 [appliance] "[ 0.418259] cryptomgr_test (27) used greatest stack depth: 14040 bytes left" #277: +1084928837 [appliance] "[ 0.420018] Initialise system trusted keyring" #278: +1086194503 [appliance] "[ 0.421262] HugeTLB registered 1 GB page size, pre-allocated 0 pages" #279: +1086195552 [appliance] "[ 0.422122] HugeTLB registered 2 MB page size, pre-allocated 0 pages" #280: +1096801156 [appliance] "[ 0.431895] zbud: loaded" #281: +1098000671 [appliance] "[ 0.433080] VFS: Disk quotas dquot_6.6.0" #282: +1098001668 [appliance] "[ 0.433782] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)" #283: +1101990523 [appliance] "[ 0.437080] Key type big_key registered" #284: +1103107946 [appliance] "[ 0.438188] cryptomgr_test (35) used greatest stack depth: 13688 bytes left" #285: +1108012816 [appliance] "[ 0.443089] cryptomgr_test (53) used greatest stack depth: 13312 bytes left" #286: +1110587682 [appliance] "[ 0.445658] NET: Registered protocol family 38" #287: +1110588585 [appliance] "[ 0.446310] Key type asymmetric registered" #288: +1111683339 [appliance] "[ 0.446862] Asymmetric key parser 'x509' registered" #289: +1111684136 [appliance] "[ 0.447630] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)" #290: +1112765831 [appliance] "[ 0.448838] io scheduler noop registered" #291: +1113863222 [appliance] "[ 0.449453] io scheduler deadline registered" #292: +1115137220 [appliance] "[ 0.450230] io scheduler cfq registered (default)" #293: +1117435140 [appliance] "[ 0.452510] pci_hotplug: PCI Hot Plug PCI Core version: 0.5" #294: +1117436103 [appliance] "[ 0.453284] pciehp: PCI Express Hot Plug Controller Driver version: 0.4" #295: +1118513989 [appliance] "[ 0.454591] Serial: 8250/16550 driver, 32 ports, IRQ sharing enabled" #296: +1145062075 [appliance] "[ 0.480097] serial8250: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A" #297: +1153153896 [appliance] "[ 0.488185] Non-volatile memory driver v1.3" #298: +1153155866 [appliance] "[ 0.488857] Linux agpgart interface v0.103" #299: +1157747539 [appliance] "[ 0.492786] scsi host0: ata_piix" #300: +1157749299 [appliance] "[ 0.493684] scsi host1: ata_piix" #301: +1158861178 [appliance] "[ 0.494316] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc060 irq 14" #302: +1159963490 [appliance] "[ 0.495207] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc068 irq 15" #303: +1161876898 [appliance] "[ 0.496899] libphy: Fixed MDIO Bus: probed" #304: +1161878687 [appliance] "[ 0.497670] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver" #305: +1162983308 [appliance] "[ 0.498565] ehci-pci: EHCI PCI platform driver" #306: +1164121293 [appliance] "[ 0.499187] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver" #307: +1164123059 [appliance] "[ 0.500043] ohci-pci: OHCI PCI platform driver" #308: +1165230668 [appliance] "[ 0.500691] uhci_hcd: USB Universal Host Controller Interface driver" #309: +1166336261 [appliance] "[ 0.501984] usbcore: registered new interface driver usbserial" #310: +1167467800 [appliance] "[ 0.502810] usbcore: registered new interface driver usbserial_generic" #311: +1168723820 [appliance] "[ 0.503787] usbserial: USB Serial support registered for generic" #312: +1168725571 [appliance] "[ 0.504649] i8042: PNP: No PS/2 controller found. Probing ports directly." #313: +1171454375 [appliance] "[ 0.506500] serio: i8042 KBD port at 0x60,0x64 irq 1" #314: +1171456085 [appliance] "[ 0.507235] serio: i8042 AUX port at 0x60,0x64 irq 12" #315: +1172549063 [appliance] "[ 0.508627] mousedev: PS/2 mouse device common for all mice" #316: +1175230457 [appliance] "[ 0.510265] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input0" #317: +1178933010 [appliance] "[ 0.513955] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input3" #318: +1180187505 [appliance] "[ 0.515249] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0" #319: +1180188936 [appliance] "[ 0.516189] rtc_cmos rtc_cmos: alarms up to one day, 114 bytes nvram" #320: +1181292059 [appliance] "[ 0.517223] device-mapper: uevent: version 1.0.3" #321: +1182381470 [appliance] "[ 0.518411] input: VirtualPS/2 VMware VMMouse as /devices/platform/i8042/serio1/input/input2" #322: +1184946735 [appliance] "[ 0.519982] device-mapper: ioctl: 4.34.0-ioctl (2015-10-28) initialised: dm-devel@redhat.com" #323: +1186769372 [appliance] "[ 0.521814] hidraw: raw HID events driver (C) Jiri Kosina" #324: +1186770786 [appliance] "[ 0.522692] usbcore: registered new interface driver usbhid" #325: +1187882258 [appliance] "[ 0.523465] usbhid: USB HID core driver" #326: +1189160630 [appliance] "[ 0.524228] drop_monitor: Initializing network drop monitor service" #327: +1189162143 [appliance] "[ 0.525263] ip_tables: (C) 2000-2006 Netfilter Core Team" #328: +1190265540 [appliance] "[ 0.526130] Initializing XFRM netlink socket" #329: +1192578953 [appliance] "[ 0.527626] NET: Registered protocol family 10" #330: +1194254641 [appliance] "[ 0.529289] mip6: Mobile IPv6" #331: +1194256061 [appliance] "[ 0.529747] NET: Registered protocol family 17" #332: +1195882927 [appliance] "[ 0.530947] microcode: CPU0 sig=0x306e4, pf=0x1, revision=0x1" #333: +1195884296 [appliance] "[ 0.531850] microcode: Microcode Update Driver: v2.01 , Peter Oruba" #334: +1196997783 [appliance] "[ 0.533049] AVX version of gcm_enc/dec engaged." #335: +1198101795 [appliance] "[ 0.533635] AES CTR mode by8 optimization enabled" #336: +1200175058 [appliance] "[ 0.535219] cryptomgr_test (85) used greatest stack depth: 13224 bytes left" #337: +1227052297 [appliance] "[ 0.562079] registered taskstats version 1" #338: +1227053661 [appliance] "[ 0.562665] Loading compiled-in X.509 certificates" #339: +1229353598 [appliance] "[ 0.564411] Loaded X.509 cert 'Fedora kernel signing key: d33a3fa294f19598ff71e1ac24c3cdc70d17052c'" #340: +1230457345 [appliance] "[ 0.565625] cryptomgr_test (100) used greatest stack depth: 12696 bytes left" #341: +1231656097 [appliance] "[ 0.566739] zswap: loaded using pool lzo/zbud" #342: +1233764791 [appliance] "[ 0.568775] Magic number: 8:862:483" #343: +1233766158 [appliance] "[ 0.569406] rtc_cmos rtc_cmos: setting system clock to 2016-03-21 13:29:38 UTC (1458566978)" #344: +1320206405 [appliance] "[ 0.655210] Freeing unused kernel memory: 3536K (ffffffff81f76000 - ffffffff822ea000)" #345: +1320208181 [appliance] "[ 0.656265] Write protecting the kernel read-only data: 14336k" #346: +1323496681 [appliance] "[ 0.658522] Freeing unused kernel memory: 1480K (ffff88000188e000 - ffff880001a00000)" #347: +1325864022 [appliance] "[ 0.660902] Freeing unused kernel memory: 436K (ffff880001d93000 - ffff880001e00000)" #348: +1327829281 [appliance] "supermin: mounting /proc" #349: +1327830625 [appliance] "supermin: ext2 mini initrd starting up: 5.1.15 glibc" #350: +1329120815 [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: +1330241164 [appliance] "supermin: uptime: 0.46 0.13" #352: +1331422864 [appliance] "supermin: mounting /sys" #353: +1331424287 [appliance] "supermin: internal insmod crc32-pclmul.ko" #354: +1334241114 [appliance] "supermin: internal insmod crc32c-intel.ko" #355: +1336315312 [appliance] "supermin: internal insmod crct10dif-pclmul.ko" #356: +1338244813 [appliance] "supermin: internal insmod crc32.ko" #357: +1340005297 [appliance] "supermin: internal insmod virtio.ko" #358: +1341788572 [appliance] "supermin: internal insmod virtio_ring.ko" #359: +1343730742 [appliance] "supermin: internal insmod virtio_blk.ko" #360: +1345873826 [appliance] "supermin: internal insmod virtio-rng.ko" #361: +1347700131 [appliance] "supermin: internal insmod virtio_console.ko" #362: +1350110604 [appliance] "supermin: internal insmod virtio_net.ko" #363: +1352493296 [appliance] "supermin: internal insmod virtio_scsi.ko" #364: +1354574986 [appliance] "supermin: internal insmod virtio_balloon.ko" #365: +1356552108 [appliance] "supermin: internal insmod virtio_input.ko" #366: +1358390177 [appliance] "supermin: internal insmod virtio_mmio.ko" #367: +1360798906 [appliance] "supermin: internal insmod virtio_pci.ko" #368: +1362930147 [appliance] "[ 0.697879] virtio-pci 0000:00:02.0: PCI->APIC IRQ transform: INT A -> IRQ 10" #369: +1362931684 [appliance] "[ 0.698911] virtio-pci 0000:00:02.0: virtio_pci: leaving for legacy driver" #370: +1366331050 [appliance] "[ 0.701383] scsi host2: Virtio SCSI HBA" #371: +1367880087 [appliance] "[ 0.702949] virtio-pci 0000:00:03.0: PCI->APIC IRQ transform: INT A -> IRQ 11" #372: +1367881560 [appliance] "[ 0.703957] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver" #373: +1371959532 [appliance] "[ 0.706929] scsi 2:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #374: +1402117605 [appliance] "[ 0.737146] scsi 2:0:1:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5" #375: +1542641127 [appliance] "[ 0.875888] sd 2:0:0:0: [sda] 8 512-byte logical blocks: (4.10 kB/4.00 KiB)" #376: +1544370664 [appliance] "[ 0.879450] sd 2:0:0:0: Attached scsi generic sg0 type 0" #377: +1546369186 [appliance] "[ 0.881440] sd 2:0:1:0: [sdb] 8388608 512-byte logical blocks: (4.29 GB/4.00 GiB)" #378: +1547504612 [appliance] "[ 0.882571] sd 2:0:0:0: [sda] Write Protect is off" #379: +1547505767 [appliance] "[ 0.883496] sd 2:0:1:0: [sdb] Write Protect is off" #380: +1548605793 [appliance] "[ 0.884277] sd 2:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #381: +1549697739 [appliance] "[ 0.885649] sd 2:0:1:0: Attached scsi generic sg1 type 0" #382: +1552441690 [appliance] "[ 0.887501] sd 2:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA" #383: +1557893117 [appliance] "[ 0.892942] sd 2:0:1:0: [sdb] Attached SCSI disk" #384: +1557894605 [appliance] "[ 0.893678] Dev sda: unable to read RDB block 8" #385: +1558988993 [appliance] "[ 0.894306] sda: unable to read partition table" #386: +1558989592 [appliance] "[ 0.894953] sda: partition table beyond EOD, enabling native capacity" #387: +1562176775 [appliance] "[ 0.897240] Dev sda: unable to read RDB block 8" #388: +1562177873 [appliance] "[ 0.897873] sda: unable to read partition table" #389: +1563269542 [appliance] "[ 0.898507] sda: partition table beyond EOD, truncated" #390: +1565133887 [appliance] "[ 0.900204] sd 2:0:0:0: [sda] Attached SCSI disk" #391: +1565134869 [appliance] "supermin: internal insmod crc-ccitt.ko" #392: +1567433354 [appliance] "supermin: internal insmod crc-itu-t.ko" #393: +1569097820 [appliance] "supermin: internal insmod crc8.ko" #394: +1570672721 [appliance] "supermin: internal insmod libcrc32c.ko" #395: +1572726278 [appliance] "supermin: picked /sys/block/sdb/dev as root device" #396: +1573859171 [appliance] "supermin: creating /dev/root as block special 8:16" #397: +1573860071 [appliance] "supermin: mounting new root on /root" #398: +1576032045 [appliance] "[ 0.911100] EXT4-fs (sdb): mounting ext2 file system using the ext4 subsystem" #399: +1599100251 [appliance] "[ 0.934100] EXT4-fs (sdb): mounted filesystem without journal. Opts: " #400: +1599103045 [appliance] "supermin: chroot" #401: +1645930570 [appliance] "Starting /init script ..." #402: +1807453606 [appliance] "[ 1.142444] ldconfig (378) used greatest stack depth: 11392 bytes left" #403: +1854275508 [appliance] "[ 1.189308] random: systemd-tmpfile urandom read with 68 bits of entropy available" #404: +1856906023 [appliance] "[/usr/lib/tmpfiles.d/journal-nocow.conf:26] Failed to replace specifiers: /var/log/journal/%m" #405: +1859767199 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:26] Failed to replace specifiers: /run/log/journal/%m" #406: +1859769347 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:28] Failed to replace specifiers: /run/log/journal/%m" #407: +1860864626 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:29] Failed to replace specifiers: /run/log/journal/%m" #408: +1861967298 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:32] Failed to replace specifiers: /var/log/journal/%m" #409: +1863070517 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:34] Failed to replace specifiers: /var/log/journal/%m" #410: +1864176511 [appliance] "[/usr/lib/tmpfiles.d/systemd.conf:35] Failed to replace specifiers: /var/log/journal/%m" #411: +1867800714 [appliance] "UDEVD=/usr/lib/systemd/systemd-udevd" #412: +1873105035 [appliance] "starting version 222" #413: +2011532141 [appliance] "[ 1.346533] piix4_smbus 0000:00:01.3: PCI->APIC IRQ transform: INT A -> IRQ 9" #414: +2018109867 [appliance] "[ 1.353157] piix4_smbus 0000:00:01.3: SMBus Host Controller at 0x700, revision 0" #415: +2077123649 [appliance] "[ 1.412141] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1e452ea631d, max_idle_ns: 440795244572 ns" #416: +2096643045 [appliance] "[ 1.431691] random: nonblocking pool is initialized" #417: +2253102015 [appliance] "[ 1.588081] input: PC Speaker as /devices/platform/pcspkr/input/input4" #418: +2303285259 [appliance] "+ grep -sq guestfs_network=1 /proc/cmdline" #419: +2307579413 [appliance] "+ grep -sq guestfs_rescue=1 /proc/cmdline" #420: +2311753198 [appliance] "+ grep -sq guestfs_noreboot=1 /proc/cmdline" #421: +2317130645 [appliance] "+ grep -sq guestfs_boot_analysis=1 /proc/cmdline" #422: +2321659737 [appliance] "+ guestfs_boot_analysis=1" #423: +2321661141 [appliance] "++ grep -Eo 'guestfs_channel=[^[:space:]]+' /proc/cmdline" #424: +2324763734 [appliance] "+ eval" #425: +2324765045 [appliance] "+ grep -sq selinux=1 /proc/cmdline" #426: +2327276422 [appliance] "+ shopt -s nullglob" #427: +2327277708 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #428: +2328388268 [appliance] "+ echo 300" #429: +2328389315 [appliance] "+ for f in '/sys/block/sd*/device/timeout'" #430: +2328389667 [appliance] "+ echo 300" #431: +2329526590 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #432: +2330667372 [appliance] "+ echo noop" #433: +2331914413 [appliance] "+ for f in '/sys/block/{h,s,ub,v}d*/queue/scheduler'" #434: +2331915727 [appliance] "+ echo noop" #435: +2331916077 [appliance] "+ shopt -u nullglob" #436: +2333011759 [appliance] "+ ip addr add 127.0.0.1/8 brd + dev lo scope host" #437: +2337722298 [appliance] "+ ip link set dev lo up" #438: +2340459359 [appliance] "+ test '' = 1" #439: +2340460701 [appliance] "+ mdadm -As --auto=yes --run" #440: +2350495424 [appliance] "mdadm: No arrays found in config file or automatically" #441: +2350496799 [appliance] "+ modprobe dm_mod" #442: +2354468441 [appliance] "+ lvmetad" #443: +2363152406 [appliance] "+ lvm vgchange -aay --sysinit" #444: +2374153083 [appliance] " lvmetad is not active yet, using direct activation during sysinit" #445: +2380155532 [appliance] "+ ldmtool create all" #446: +2389195151 [appliance] "[" #447: +2389196641 [appliance] "]" #448: +2391090082 [appliance] "+ test 1 = 1" #449: +2391091422 [appliance] "+ test 1 '!=' 1" #450: +2391091743 [appliance] "+ test '' = 1" #451: +2391092084 [appliance] "+ cmd=guestfsd" #452: +2392228459 [appliance] "+ test x '!=' x" #453: +2392229571 [appliance] "+ test 1 = 1" #454: +2392229898 [appliance] "+ cmd='guestfsd --verbose'" #455: +2392230262 [appliance] "+ test '' = 1" #456: +2393366918 [appliance] "+ echo guestfsd --verbose" #457: +2393367984 [appliance] "guestfsd --verbose" #458: +2393368264 [appliance] "+ guestfsd --verbose" #459: +2410537823 [appliance] "trying to open virtio-serial channel '/dev/virtio-ports/org.libguestfs.channel.0'" #460: +2410539339 [appliance] "udevadm --debug settle" #461: +2416337593 [appliance] "calling: settle" #462: +2416429380 [launch_done] "launch done callback" #463: +2416444718 [library] "recv_from_daemon: received GUESTFS_LAUNCH_FLAG" #464: +2416446036 [library] "appliance is up" #465: +2416473038 [trace] "launch = 0" #466: +2416474674 [trace] "close" #467: +2416476040 [library] "closing guestfs handle 0xe417a0 (state 2)" #468: +2416481316 [trace] "internal_autosync" #469: +2420334816 [appliance] "guestfsd: main_loop: new request, len 0x28" #470: +2420336237 [appliance] "umount-all: /proc/mounts: fsname=/dev/root dir=/ type=ext2 opts=rw,noatime,block_validity,barrier,user_xattr,acl freq=0 passno=0" #471: +2421458715 [appliance] "umount-all: /proc/mounts: fsname=/proc dir=/proc type=proc opts=rw,relatime freq=0 passno=0" #472: +2422586767 [appliance] "umount-all: /proc/mounts: fsname=/sys dir=/sys type=sysfs opts=rw,relatime freq=0 passno=0" #473: +2423774319 [appliance] "umount-all: /proc/mounts: fsname=tmpfs dir=/run type=tmpfs opts=rw,nosuid,relatime,size=93972k,mode=755 freq=0 passno=0" #474: +2423775832 [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" #475: +2431567957 [appliance] "fsync /dev/sda" #476: +2431569391 [appliance] "guestfsd: main_loop: proc 282 (internal_autosync) took 0.01 seconds" #477: +2432733033 [trace] "internal_autosync = 0" #478: +2432735643 [library] "sending SIGTERM to process 38620" #479: +2446302652 [close] "close callback" #480: +2446316583 [library] "command: run: rm" #481: +2446318436 [library] "command: run: \ -rf /home/kchamart/src/rwmj-fork-libguestfs/tmp/libguestfsPGhdmX" #482: +2448488200 [library] "command: run: rm" #483: +2448489550 [library] "command: run: \ -rf /tmp/libguestfs106Kab" Analyzing the results ... activity 0: name = run start - end = 0.0 - 2447361087.5 mean elapsed = 2447361088.5 variance = 1491076662312.2 s.d = 1221096.5 percent = 100.0 activity 1: name = supermin:build start - end = 117793.0 - 16458616.0 mean elapsed = 16340824.0 variance = 1582755221776.0 s.d = 1258076.0 percent = 0.7 activity 2: name = qemu:feature-detect start - end = 16498474.5 - 292135938.5 mean elapsed = 275637465.0 variance = 67440081020481.0 s.d = 8212191.0 percent = 11.3 activity 3: name = qemu start - end = 294350291.0 - 2447361087.5 mean elapsed = 2153010797.5 variance = 66202119651492.2 s.d = 8136468.5 percent = 88.0 activity 4: name = qemu:overhead start - end = 294350291.0 - 484595303.0 mean elapsed = 190245013.0 variance = 3393885062500.0 s.d = 1842250.0 percent = 7.8 activity 5: name = bios:overhead start - end = 484595304.0 - 729194733.0 mean elapsed = 244599430.0 variance = 5610815488656.0 s.d = 2368716.0 percent = 10.0 activity 6: name = sgabios start - end = 484595304.0 - 487762797.0 mean elapsed = 3167494.0 variance = 4900560016.0 s.d = 70004.0 percent = 0.1 activity 7: name = seabios start - end = 487762798.0 - 729194733.0 mean elapsed = 241431936.0 variance = 5284076858944.0 s.d = 2298712.0 percent = 9.9 activity 8: name = kernel start - end = 729194734.0 - 2447361087.5 mean elapsed = 1718166354.5 variance = 152459138731790.2 s.d = 12347434.5 percent = 70.2 activity 9: name = kernel:overhead start - end = 729194734.0 - 1336223455.5 mean elapsed = 607028722.5 variance = 25130565028560.2 s.d = 5013039.5 percent = 24.8 activity 10: name = supermin:mini-initrd start - end = 1336223456.5 - 1616465607.0 mean elapsed = 280242151.5 variance = 80456083182092.2 s.d = 8969731.5 percent = 11.5 activity 11: name = supermin: internal insmod crc32-pclmul.ko start - end = 1339836829.5 - 1342691092.5 mean elapsed = 2854264.0 variance = 1401528969.0 s.d = 37437.0 percent = 0.1 activity 12: name = supermin: internal insmod crc32c-intel.ko start - end = 1342691093.5 - 1344783005.5 mean elapsed = 2091913.0 variance = 313821225.0 s.d = 17715.0 percent = 0.1 activity 13: name = supermin: internal insmod crct10dif-pclmul.ko start - end = 1344783006.5 - 1346725848.0 mean elapsed = 1942842.5 variance = 177995622.2 s.d = 13341.5 percent = 0.1 activity 14: name = supermin: internal insmod crc32.ko start - end = 1346725849.0 - 1348531002.0 mean elapsed = 1805154.0 variance = 1995408900.0 s.d = 44670.0 percent = 0.1 activity 15: name = supermin: internal insmod virtio.ko start - end = 1348531003.0 - 1350363654.0 mean elapsed = 1832652.0 variance = 2438088129.0 s.d = 49377.0 percent = 0.1 activity 16: name = supermin: internal insmod virtio_ring.ko start - end = 1350363655.0 - 1352281704.5 mean elapsed = 1918050.5 variance = 581750280.2 s.d = 24119.5 percent = 0.1 activity 17: name = supermin: internal insmod virtio_blk.ko start - end = 1352281705.5 - 1354406731.5 mean elapsed = 2125027.0 variance = 326055249.0 s.d = 18057.0 percent = 0.1 activity 18: name = supermin: internal insmod virtio-rng.ko start - end = 1354406732.5 - 1356254460.5 mean elapsed = 1847729.0 variance = 458987776.0 s.d = 21424.0 percent = 0.1 activity 19: name = supermin: internal insmod virtio_console.ko start - end = 1356254461.5 - 1358613184.0 mean elapsed = 2358723.5 variance = 2678010750.2 s.d = 51749.5 percent = 0.1 activity 20: name = supermin: internal insmod virtio_net.ko start - end = 1358613185.0 - 1360972357.0 mean elapsed = 2359173.0 variance = 553143361.0 s.d = 23519.0 percent = 0.1 activity 21: name = supermin: internal insmod virtio_scsi.ko start - end = 1360972358.0 - 1363097879.5 mean elapsed = 2125522.5 variance = 1921288056.2 s.d = 43832.5 percent = 0.1 activity 22: name = supermin: internal insmod virtio_balloon.ko start - end = 1363097880.5 - 1365040604.5 mean elapsed = 1942725.0 variance = 1183153609.0 s.d = 34397.0 percent = 0.1 activity 23: name = supermin: internal insmod virtio_input.ko start - end = 1365040605.5 - 1366877157.5 mean elapsed = 1836553.0 variance = 2298256.0 s.d = 1516.0 percent = 0.1 activity 24: name = supermin: internal insmod virtio_mmio.ko start - end = 1366877158.5 - 1369050345.0 mean elapsed = 2173187.5 variance = 55479798222.2 s.d = 235541.5 percent = 0.1 activity 25: name = supermin: internal insmod virtio_pci.ko start - end = 1369050346.0 - 1582209123.0 mean elapsed = 213158778.0 variance = 77842064524225.0 s.d = 8822815.0 percent = 8.7 activity 26: name = supermin: internal insmod crc-ccitt.ko start - end = 1582209124.0 - 1584664014.5 mean elapsed = 2454891.5 variance = 24462993242.2 s.d = 156406.5 percent = 0.1 activity 27: name = supermin: internal insmod crc-itu-t.ko start - end = 1584664015.5 - 1586440175.5 mean elapsed = 1776161.0 variance = 12475773025.0 s.d = 111695.0 percent = 0.1 activity 28: name = supermin: internal insmod crc8.ko start - end = 1586440176.5 - 1588102840.5 mean elapsed = 1662665.0 variance = 7702519696.0 s.d = 87764.0 percent = 0.1 activity 29: name = supermin: internal insmod libcrc32c.ko start - end = 1588102841.5 - 1590318560.5 mean elapsed = 2215720.0 variance = 26296838569.0 s.d = 162163.0 percent = 0.1 activity 30: name = /init start - end = 1616465608.0 - 2391047135.0 mean elapsed = 774581528.0 varianLinux 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 ce = 343929079355625.0 s.d = 18545325.0 percent = 31.6 activity 31: name = bash:overhead start - end = 1616465608.0 - 1657131444.0 mean elapsed = 40665837.0 variance = 37966399009344.0 s.d = 6161688.0 percent = 1.7 activity 32: name = guestfsd start - end = 2391047136.0 - 2432073060.5 mean elapsed = 41025925.5 variance = 2848893321822.2 s.d = 1687866.5 percent = 1.7 activity 33: name = shutdown start - end = 2416840184.5 - 2447361087.5 mean elapsed = 30520904.0 variance = 480146441476.0 s.d = 692926.0 percent = 1.2 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.447361s ±1.2ms (100.0%) 0.000118s: │ ▲ supermin:build mean:0.016341s ±1.3ms (0.7%) │ │ 0.016459s: │ ▼ 0.016498s: │ ▲ qemu:feature-detect mean:0.275637s ±8.2ms (11.3%) │ │ 0.292136s: │ ▼ │ 0.294350s: │ ▲ ▲ qemu mean:2.153011s ±8.1ms (88.0%) qemu:overhead mean:0.190245s ±1.8ms (7.8%) │ │ │ 0.484595s: │ │ ▼ 0.484595s: │ │ ▲ ▲ bios:overhead mean:0.244599s ±2.4ms (10.0%) sgabios mean:0.003167s ±0.1ms (0.1%) │ │ │ │ 0.487763s: │ │ │ ▼ 0.487763s: │ │ │ ▲ seabios mean:0.241432s ±2.3ms (9.9%) │ │ │ │ 0.729195s: │ │ ▼ ▼ 0.729195s: │ │ ▲ ▲ kernel mean:1.718166s ±12.3ms (70.2%) kernel:overhead mean:0.607029s ±5.0ms (24.8%) │ │ │ │ 1.336223s: │ │ │ ▼ 1.336223s: │ │ │ ▲ supermin:mini-initrd mean:0.280242s ±9.0ms (11.5%) │ │ │ │ 1.339837s: │ │ │ │ ▲ supermin: internal insmod crc32-pclmul.ko mean:0.002854s ±0.0ms (0.1%) │ │ │ │ │ 1.342691s: │ │ │ │ ▼ 1.342691s: │ │ │ │ ▲ supermin: internal insmod crc32c-intel.ko mean:0.002092s ±0.0ms (0.1%) │ │ │ │ │ 1.344783s: │ │ │ │ ▼ 1.344783s: │ │ │ │ ▲ supermin: internal insmod crct10dif-pclmul.ko mean:0.001943s ±0.0ms (0.1%) │ │ │ │ │ 1.346726s: │ │ │ │ ▼ 1.346726s: │ │ │ │ ▲ supermin: internal insmod crc32.ko mean:0.001805s ±0.0ms (0.1%) │ │ │ │ │ 1.348531s: │ │ │ │ ▼ 1.348531s: │ │ │ │ ▲ supermin: internal insmod virtio.ko mean:0.001833s ±0.0ms (0.1%) │ │ │ │ │ 1.350364s: │ │ │ │ ▼ 1.350364s: │ │ │ │ ▲ supermin: internal insmod virtio_ring.ko mean:0.001918s ±0.0ms (0.1%) │ │ │ │ │ 1.352282s: │ │ │ │ ▼ 1.352282s: │ │ │ │ ▲ supermin: internal insmod virtio_blk.ko mean:0.002125s ±0.0ms (0.1%) │ │ │ │ │ 1.354407s: │ │ │ │ ▼ 1.354407s: │ │ │ │ ▲ supermin: internal insmod virtio-rng.ko mean:0.001848s ±0.0ms (0.1%) │ │ │ │ │ 1.356254s: │ │ │ │ ▼ 1.356254s: │ │ │ │ ▲ supermin: internal insmod virtio_console.ko mean:0.002359s ±0.1ms (0.1%) │ │ │ │ │ 1.358613s: │ │ │ │ ▼ 1.358613s: │ │ │ │ ▲ supermin: internal insmod virtio_net.ko mean:0.002359s ±0.0ms (0.1%) │ │ │ │ │ 1.360972s: │ │ │ │ ▼ 1.360972s: │ │ │ │ ▲ supermin: internal insmod virtio_scsi.ko mean:0.002126s ±0.0ms (0.1%) │ │ │ │ │ 1.363098s: │ │ │ │ ▼ 1.363098s: │ │ │ │ ▲ supermin: internal insmod virtio_balloon.ko mean:0.001943s ±0.0ms (0.1%) │ │ │ │ │ 1.365041s: │ │ │ │ ▼ 1.365041s: │ │ │ │ ▲ supermin: internal insmod virtio_input.ko mean:0.001837s ±0.0ms (0.1%) │ │ │ │ │ 1.366877s: │ │ │ │ ▼ 1.366877s: │ │ │ │ ▲ supermin: internal insmod virtio_mmio.ko mean:0.002173s ±0.2ms (0.1%) │ │ │ │ │ 1.369050s: │ │ │ │ ▼ 1.369050s: │ │ │ │ ▲ supermin: internal insmod virtio_pci.ko mean:0.213159s ±8.8ms (8.7%) │ │ │ │ │ 1.582209s: │ │ │ │ ▼ 1.582209s: │ │ │ │ ▲ supermin: internal insmod crc-ccitt.ko mean:0.002455s ±0.2ms (0.1%) │ │ │ │ │ 1.584664s: │ │ │ │ ▼ 1.584664s: │ │ │ │ ▲ supermin: internal insmod crc-itu-t.ko mean:0.001776s ±0.1ms (0.1%) │ │ │ │ │ 1.586440s: │ │ │ │ ▼ 1.586440s: │ │ │ │ ▲ supermin: internal insmod crc8.ko mean:0.001663s ±0.1ms (0.1%) │ │ │ │ │ 1.588103s: │ │ │ │ ▼ 1.588103s: │ │ │ │ ▲ supermin: internal insmod libcrc32c.ko mean:0.002216s ±0.2ms (0.1%) │ │ │ │ │ 1.590319s: │ │ │ │ ▼ │ │ │ │ 1.616466s: │ │ │ ▼ 1.616466s: │ │ │ ▲ ▲ /init mean:0.774582s ±18.5ms (31.6%) bash:overhead mean:0.040666s ±6.2ms (1.7%) │ │ │ │ │ 1.657131s: │ │ │ │ ▼ │ │ │ │ 2.391047s: │ │ │ ▼ 2.391047s: │ │ │ ▲ guestfsd mean:0.041026s ±1.7ms (1.7%) │ │ │ │ 2.416840s: │ │ │ │ ▲ shutdown mean:0.030521s ±0.7ms (1.2%) │ │ │ │ │ 2.432073s: │ │ │ ▼ │ │ │ │ │ 2.447361s: ▼ ▼ ▼ ▼