This bug is an old one in smartpm seems to be a problem of locking/threading inside smart see,

https://bugs.launchpad.net/smart/+bug/244038

I couldn't reproduce this issue, i iterated 115 TIMES running smart tests over core-image-sato-sdk, qemux86-64 and using cpulimit at 5% over qemu.

$ times=0; retcode=0; while [ $retcode -eq 0 ]; do bitbake core-image-sato-sdk -c testimage; retcode=$?; times=$((times+1)); done
$ cpulimit -p 3634  -l 5

May be this issue needs to be set as Normal priority, because isn't appear too often and seems to be related to AB load.

My fault, moving it to M1 again. CCB should agree on any milestone movement.

This is a random issue and has not been observed recently.

We're seeing this again on the new build cluster:
http://autobuilder.yocto.io:8010/builders/nightly-x86-64/builds/39/steps/Running%20Sanity%20Tests/logs/stdio

Also:

http://autobuilder.yocto.io:8010/builders/nightly-mips/builds/27/steps/Running%20Sanity%20Tests/logs/stdio
http://autobuilder.yocto.io:8010/builders/nightly-qa-systemd/builds/23/steps/Running%20Sanity%20Tests/logs/stdio

For https://autobuilder.yoctoproject.org/main/builders/nightly-x86-64/builds/957/steps/Running%20Sanity%20Tests/logs/stdio we have some data in the logs which is helpful:

[pokybuild@fedora23 build]$ cat tmp/work/qemux86_64-poky-linux/core-image-sato-sdk/1.0-r0/testimage/qemu_boot_log
[    0.000000] Linux version 4.8.0-rc4-yocto-standard (pokybuild@opensuse421) (gcc version 6.2.0 (GCC) ) #1 SMP PREEMPT Sun Sep 4 16:48:42 GMT 2016
[    0.000000] Command line: root=/dev/vda rw highres=off  console=tty1 console=ttyS0,115200n8 printk.time=1 mem=256M ip=192.168.7.6::192.168.7.5:255.255.255.0 vga=0 uvesafb.mode_option=640x480-32 oprofile.timer=1
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   Centaur CentaurHauls
[    0.000000] x86/fpu: Legacy x87 FPU detected.
[    0.000000] x86/fpu: Using 'eager' FPU context switches.
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000000ffdbfff] usable
[    0.000000] BIOS-e820: [mem 0x000000000ffdc000-0x000000000fffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] e820: user-defined physical RAM map:
[    0.000000] user: [mem 0x0000000000000000-0x000000000009fbff] usable
[    0.000000] user: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[    0.000000] user: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[    0.000000] user: [mem 0x0000000000100000-0x000000000ffdbfff] usable
[    0.000000] user: [mem 0x000000000ffdc000-0x000000000fffffff] reserved
[    0.000000] user: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[    0.000000] user: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[    0.000000] SMBIOS 2.8 present.
[    0.000000] Hypervisor detected: KVM
[    0.000000] e820: last_pfn = 0xffdc max_arch_pfn = 0x400000000
[    0.000000] x86/PAT: Configuration [0-7]: WB  WC  UC- UC  WB  WC  UC- UC  
[    0.000000] found SMP MP-table at [mem 0x000f6bc0-0x000f6bcf] mapped at [ffff8800000f6bc0]
[    0.000000] Scanning 1 areas for low memory corruption
[    0.000000] ACPI: Early table checksum verification disabled
[    0.000000] ACPI: RSDP 0x00000000000F69D0 000014 (v00 BOCHS )
[    0.000000] ACPI: RSDT 0x000000000FFE1737 000030 (v01 BOCHS  BXPCRSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACP 0x000000000FFE1613 000074 (v01 BOCHS  BXPCFACP 00000001 BXPC 00000001)
[    0.000000] ACPI: DSDT 0x000000000FFE0040 0015D3 (v01 BOCHS  BXPCDSDT 00000001 BXPC 00000001)
[    0.000000] ACPI: FACS 0x000000000FFE0000 000040
[    0.000000] ACPI: APIC 0x000000000FFE1687 000078 (v01 BOCHS  BXPCAPIC 00000001 BXPC 00000001)
[    0.000000] ACPI: HPET 0x000000000FFE16FF 000038 (v01 BOCHS  BXPCHPET 00000001 BXPC 00000001)
[    0.000000] kvm-clock: Using msrs 4b564d01 and 4b564d00
[    0.000000] kvm-clock: cpu 0, msr 0:ffdb001, primary cpu clock
[    0.000000] kvm-clock: using sched offset of 1801799776 cycles
[    0.000000] clocksource: kvm-clock: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000001000-0x0000000000ffffff]
[    0.000000]   DMA32    [mem 0x0000000001000000-0x000000000ffdbfff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000001000-0x000000000009efff]
[    0.000000]   node   0: [mem 0x0000000000100000-0x000000000ffdbfff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000001000-0x000000000ffdbfff]
[    0.000000] ACPI: PM-Timer IO Port: 0x608
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[    0.000000] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[    0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] e820: [mem 0x10000000-0xfeffbfff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on KVM
[    0.000000] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[    0.000000] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:1 nr_node_ids:1
[    0.000000] percpu: Embedded 34 pages/cpu @ffff88000fc00000 s100504 r8192 d30568 u2097152
[    0.000000] KVM setup async PF for cpu 0
[    0.000000] kvm-stealtime: cpu 0, msr fc0c900
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 64357
[    0.000000] Kernel command line: root=/dev/vda rw highres=off  console=tty1 console=ttyS0,115200n8 printk.time=1 mem=256M ip=192.168.7.6::192.168.7.5:255.255.255.0 vga=0 uvesafb.mode_option=640x480-32 oprofile.timer=1
[    0.000000] PID hash table entries: 1024 (order: 1, 8192 bytes)
[    0.000000] Dentry cache hash table entries: 32768 (order: 6, 262144 bytes)
[    0.000000] Inode-cache hash table entries: 16384 (order: 5, 131072 bytes)
[    0.000000] Memory: 238868K/261608K available (9469K kernel code, 1147K rwdata, 3672K rodata, 1376K init, 1064K bss, 22740K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] 	Build-time adjustment of leaf fanout to 64.
[    0.000000] 	RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=1
[    0.000000] NR_IRQS:4352 nr_irqs:256 16
[    0.000000] Console: colour VGA+ 80x25
[    0.000000] console [tty1] enabled
[    0.000000] console [ttyS0] enabled
[    0.000000] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.000000] tsc: Fast TSC calibration using PIT
[    0.000000] tsc: Detected 3324.869 MHz processor
[    0.339224] Calibrating delay loop (skipped) preset value.. 6649.99 BogoMIPS (lpj=3324998)
[    0.342157] pid_max: default: 32768 minimum: 301
[    0.343611] ACPI: Core revision 20160422
[    0.345862] ACPI: 1 ACPI AML tables successfully acquired and loaded
[    0.348289] 
[    0.349128] Security Framework initialized
[    0.350625] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
[    0.352600] Mountpoint-cache hash table entries: 512 (order: 0, 4096 bytes)
[    0.355181] mce: CPU supports 10 MCE banks
[    0.356681] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.358519] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.382775] Freeing SMP alternatives memory: 40K (ffffffff82078000 - ffffffff82082000)
[    0.388280] ftrace: allocating 34825 entries in 137 pages
[    0.430480] smpboot: APIC(0) Converting physical 0 to logical package 0
[    0.432837] smpboot: Max logical packages: 1
[    0.435231] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.551428] APIC calibration not consistent with PM-Timer: 113ms instead of 100ms
[    0.555767] APIC delta adjusted to PM-Timer: 6249265 (7063119)
[    0.558719] smpboot: CPU0: Intel Common KVM processor (family: 0xf, model: 0x6, stepping: 0x1)
[    0.561148] Performance Events: unsupported Netburst CPU model 6 no PMU driver, software events only.
[    0.571794] x86: Booted up 1 node, 1 CPUs
[    0.573158] smpboot: Total of 1 processors activated (6649.99 BogoMIPS)
[    0.577924] devtmpfs: initialized
[    0.591474] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[    0.599357] xor: measuring software checksum speed
[    0.614708]    prefetch64-sse:  9916.000 MB/sec
[    0.642774]    generic_sse:  6948.000 MB/sec
[    0.660585] xor: using function: prefetch64-sse (9916.000 MB/sec)
[    0.667936] pinctrl core: initialized pinctrl subsystem
[    0.669487] NET: Registered protocol family 16
[    0.674709] cpuidle: using governor menu
[    0.683327] ACPI: bus type PCI registered
[    0.684445] PCI: Using configuration type 1 for base access
[    0.719719] raid6: sse2x1   gen()  3082 MB/s
[    0.776067] raid6: sse2x1   xor()  3197 MB/s
[    0.802682] raid6: sse2x2   gen()  3625 MB/s
[    0.820687] raid6: sse2x2   xor()  4236 MB/s
[    0.842672] raid6: sse2x4   gen()  6082 MB/s
[    0.860660] raid6: sse2x4   xor()  3414 MB/s
[    0.864930] raid6: using algorithm sse2x4 gen() 6082 MB/s
[    0.866230] raid6: .... xor() 3414 MB/s, rmw enabled
[    0.868263] raid6: using intx1 recovery algorithm
[    0.869461] ACPI: Added _OSI(Module Device)
[    0.871073] ACPI: Added _OSI(Processor Device)
[    0.872382] ACPI: Added _OSI(3.0 _SCP Extensions)
[    0.873955] ACPI: Added _OSI(Processor Aggregator Device)
[    0.876993] ACPI: Interpreter enabled
[    0.878047] ACPI: (supports S0 S3 S5)
[    0.879462] ACPI: Using IOAPIC for interrupt routing
[    0.881092] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[    0.886918] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[    0.888611] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI]
[    0.890700] acpi PNP0A03:00: _OSC failed (AE_NOT_FOUND); disabling ASPM
[    0.892668] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[    0.899449] PCI host bridge to bus 0000:00
[    0.900688] pci_bus 0000:00: root bus resource [io  0x0000-0x0cf7 window]
[    0.902073] pci_bus 0000:00: root bus resource [io  0x0d00-0xffff window]
[    0.903271] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[    0.905869] pci_bus 0000:00: root bus resource [mem 0x10000000-0xfebfffff window]
[    0.908219] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.935916] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io  0x01f0-0x01f7]
[    0.937447] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io  0x03f6]
[    0.938849] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io  0x0170-0x0177]
[    0.940345] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io  0x0376]
[    0.954488] pci 0000:00:01.3: quirk: [io  0x0600-0x063f] claimed by PIIX4 ACPI
[    0.956329] pci 0000:00:01.3: quirk: [io  0x0700-0x070f] claimed by PIIX4 SMB
[    1.068363] ACPI: PCI Interrupt Link [LNKA] (IRQs 5 *10 11)
[    1.071424] ACPI: PCI Interrupt Link [LNKB] (IRQs 5 *10 11)
[    1.074161] ACPI: PCI Interrupt Link [LNKC] (IRQs 5 10 *11)
[    1.077121] ACPI: PCI Interrupt Link [LNKD] (IRQs 5 10 *11)
[    1.114361] ACPI: PCI Interrupt Link [LNKS] (IRQs *9)
[    1.117991] ACPI: Enabled 16 GPEs in block 00 to 0F
[    1.121047] vgaarb: setting as boot device: PCI:0000:00:02.0
[    1.122682] vgaarb: device added: PCI:0000:00:02.0,decodes=io+mem,owns=io+mem,locks=none
[    1.125022] vgaarb: loaded
[    1.126097] vgaarb: bridge control possible 0000:00:02.0
[    1.128105] SCSI subsystem initialized
[    1.130959] ACPI: bus type USB registered
[    1.132553] usbcore: registered new interface driver usbfs
[    1.134394] usbcore: registered new interface driver hub
[    1.136065] usbcore: registered new device driver usb
[    1.137862] pps_core: LinuxPPS API ver. 1 registered
[    1.139744] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    1.151873] PTP clock support registered
[    1.154236] Advanced Linux Sound Architecture Driver Initialized.
[    1.156211] PCI: Using ACPI for IRQ routing
[    1.158470] Bluetooth: Core ver 2.21
[    1.159612] NET: Registered protocol family 31
[    1.160926] Bluetooth: HCI device and connection manager initialized
[    1.162879] Bluetooth: HCI socket layer initialized
[    1.164371] Bluetooth: L2CAP socket layer initialized
[    1.165885] Bluetooth: SCO socket layer initialized
[    1.169496] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[    1.171597] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[    1.173373] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[    1.190719] clocksource: Switched to clocksource kvm-clock
[    1.313396] pnp: PnP ACPI init
[    1.315496] pnp: PnP ACPI: found 7 devices
[    1.344447] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[    1.347001] NET: Registered protocol family 2
[    1.348864] TCP established hash table entries: 2048 (order: 2, 16384 bytes)
[    1.355077] TCP bind hash table entries: 2048 (order: 3, 32768 bytes)
[    1.356738] TCP: Hash tables configured (established 2048 bind 2048)
[    1.358505] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    1.360222] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    1.362686] NET: Registered protocol family 1
[    1.367974] RPC: Registered named UNIX socket transport module.
[    1.369747] RPC: Registered udp transport module.
[    1.385105] RPC: Registered tcp transport module.
[    1.388214] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.390362] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    1.392305] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[    1.398272] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[    1.443524] ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 11
[    1.490207] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[    1.547514] Scanning for low memory corruption every 60 seconds
[    1.559061] futex hash table entries: 256 (order: 2, 16384 bytes)
[    1.562837] workingset: timestamp_bits=46 max_order=16 bucket_order=0
[    1.571071] NFS: Registering the id_resolver key type
[    1.574898] Key type id_resolver registered
[    1.576057] Key type id_legacy registered
[    1.579282] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    1.581401] io scheduler noop registered
[    1.582670] io scheduler deadline registered
[    1.583910] io scheduler cfq registered (default)
[    1.585337] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    1.586984] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[    1.589690] ACPI: Power Button [PWRF]
[    1.630659] ACPI: PCI Interrupt Link [LNKC] enabled at IRQ 11
[    1.632266] virtio-pci 0000:00:03.0: virtio_pci: leaving for legacy driver
[    1.672421] virtio-pci 0000:00:04.0: virtio_pci: leaving for legacy driver
[    1.716397] ACPI: PCI Interrupt Link [LNKA] enabled at IRQ 10
[    1.732839] virtio-pci 0000:00:05.0: virtio_pci: leaving for legacy driver
[    1.737809] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[    1.769556] 00:05: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[    1.794789] 00:06: ttyS1 at I/O 0x2f8 (irq = 3, base_baud = 115200) is a 16550A
[    1.798409] Linux agpgart interface v0.103
[    1.806491] random: fast init done
[    1.807695] random: crng init done
[    1.808951] [drm] Initialized drm 1.1.0 20060810
[    1.845911] brd: module loaded
[    1.874089] loop: module loaded
[    1.893097] Uniform Multi-Platform E-IDE driver
[    1.905858] piix 0000:00:01.1: IDE controller (0x8086:0x7010 rev 0x00)
[    1.915677] piix 0000:00:01.1: not 100% native mode: will probe irqs later
[    1.918563]     ide0: BM-DMA at 0xc0a0-0xc0a7
[    1.919890]     ide1: BM-DMA at 0xc0a8-0xc0af
[    2.558897] tsc: Refined TSC clocksource calibration: 3324.809 MHz
[    2.574782] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2fecd8a7a97, max_idle_ns: 440795306466 ns
[    3.146958] hdc: QEMU DVD-ROM, ATAPI CD/DVD-ROM drive
[    3.778008] hdc: MWDMA2 mode selected
[    3.785905] ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
[    3.787140] ide1 at 0x170-0x177,0x376 on irq 15
[    3.789986] ide-gd driver 1.18
[    3.803845] ide-cd driver 5.00
[    3.805790] ide-cd: hdc: ATAPI 4X DVD-ROM drive, 512kB Cache
[    3.807439] cdrom: Uniform CD-ROM driver Revision: 3.20
[    3.811640] pcnet32: pcnet32.c:v1.35 21.Apr.2008 tsbogend@alpha.franken.de
[    3.813358] e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
[    3.814773] e100: Copyright(c) 1999-2006 Intel Corporation
[    3.816112] e1000: Intel(R) PRO/1000 Network Driver - version 7.3.21-k8-NAPI
[    3.817754] e1000: Copyright (c) 1999-2006 Intel Corporation.
[    3.819179] e1000e: Intel(R) PRO/1000 Network Driver - 3.2.6-k
[    3.820534] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    3.822065] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    3.823574] ehci-pci: EHCI PCI platform driver
[    3.824893] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    3.826322] ohci-pci: OHCI PCI platform driver
[    3.827489] uhci_hcd: USB Universal Host Controller Interface driver
[    3.867138] uhci_hcd 0000:00:01.2: UHCI Host Controller
[    3.869084] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[    3.878778] uhci_hcd 0000:00:01.2: irq 11, io base 0x0000c040
[    3.880777] hub 1-0:1.0: USB hub found
[    3.881892] hub 1-0:1.0: 2 ports detected
[    3.883334] usbcore: registered new interface driver usb-storage
[    3.884907] usbcore: registered new interface driver usbserial
[    3.886601] usbcore: registered new interface driver usbserial_generic
[    3.888449] usbserial: USB Serial support registered for generic
[    3.890059] usbcore: registered new interface driver ftdi_sio
[    3.891633] usbserial: USB Serial support registered for FTDI USB Serial Device
[    3.893702] usbcore: registered new interface driver pl2303
[    3.895162] usbserial: USB Serial support registered for pl2303
[    3.896879] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[    3.900245] serio: i8042 KBD port at 0x60,0x64 irq 1
[    3.901855] serio: i8042 AUX port at 0x60,0x64 irq 12
[    3.903594] mousedev: PS/2 mouse device common for all mice
[    3.905813] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[    3.919070] rtc_cmos 00:00: RTC can wake from S4
[    3.920989] rtc_cmos 00:00: rtc core: registered rtc_cmos as rtc0
[    3.922847] rtc_cmos 00:00: alarms up to one day, y3k, 114 bytes nvram, hpet irqs
[    3.927057] md: linear personality registered for level -1
[    3.928523] md: raid0 personality registered for level 0
[    3.929972] md: raid1 personality registered for level 1
[    3.931485] md: raid10 personality registered for level 10
[    3.932952] md: multipath personality registered for level -4
[    3.934645] md: faulty personality registered for level -5
[    3.936571] device-mapper: ioctl: 4.35.0-ioctl (2016-06-23) initialised: dm-devel@redhat.com
[    3.940994] usbcore: registered new interface driver usbhid
[    3.942616] usbhid: USB HID core driver
[    3.944379] oprofile: using NMI interrupt.
[    3.945544] oprofile: using timer interrupt.
[    3.952200] u32 classifier
[    3.953282]     Actions configured
[    3.954875] NET: Registered protocol family 10
[    3.960232] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    3.962315] NET: Registered protocol family 17
[    3.963687] Key type dns_resolver registered
[    3.965383] microcode: sig=0xf61, pf=0x1, revision=0x1
[    3.966965] microcode: Microcode Update Driver: v2.01 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
[    3.972124] Btrfs loaded, crc32c=crc32c-generic
[    3.975821] console [netcon0] enabled
[    3.976957] netconsole: network logging started
[    3.978391] rtc_cmos 00:00: setting system clock to 2016-09-06 23:13:31 UTC (1473203611)
[    3.999903] IP-Config: Complete:
[    4.000983]      device=eth0, hwaddr=52:54:00:12:34:06, ipaddr=192.168.7.6, mask=255.255.255.0, gw=192.168.7.5
[    4.003316]      host=192.168.7.6, domain=, nis-domain=(none)
[    4.004877]      bootserver=255.255.255.255, rootserver=255.255.255.255, rootpath=
[    4.006995] ALSA device list:
[    4.007880]   No soundcards found.
[    4.198807] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[    4.371703] input: QEMU QEMU USB Tablet as /devices/pci0000:00/0000:00:01.2/usb1/1-1/1-1:1.0/0003:0627:0001.0001/input/input4
[    4.374848] hid-generic 0003:0627:0001.0001: input: USB HID v0.01 Pointer [QEMU QEMU USB Tablet] on usb-0000:00:01.2-1/input0
[    4.760529] input: ImExPS/2 BYD TouchPad as /devices/platform/i8042/serio1/input/input3
[    4.764892] md: Waiting for all devices to be available before autodetect
[    4.767006] md: If you don't use raid, use raid=noautodetect
[    4.771106] md: Autodetecting RAID arrays.
[    4.772593] md: Scanned 0 and added 0 devices.
[    4.774027] md: autorun ...
[    4.802585] md: ... autorun DONE.
[    4.804417] EXT4-fs (vda): couldn't mount as ext3 due to feature incompatibilities
[    4.807521] EXT4-fs (vda): couldn't mount as ext2 due to feature incompatibilities
[    4.815113] EXT4-fs (vda): mounted filesystem with ordered data mode. Opts: (null)
[    4.817670] VFS: Mounted root (ext4 filesystem) on device 253:0.
[    4.820274] devtmpfs: mounted
[    4.824204] Freeing unused kernel memory: 1376K (ffffffff81f20000 - ffffffff82078000)
[    4.832261] Write protecting the kernel read-only data: 14336k
[    4.835862] Freeing unused kernel memory: 752K (ffff880001944000 - ffff880001a00000)
[    4.840523] Freeing unused kernel memory: 424K (ffff880001d96000 - ffff880001e00000)
INIT: version 2.88 booting
[    4.896535] uvesafb: SeaBIOS Developers, SeaBIOS VBE Adapter, Rev. 1, OEM: SeaBIOS VBE(C) 2011, VBE v3.0
[    4.921498] uvesafb: no monitor limits have been set, default refresh rate will be used
[    4.942639] uvesafb: scrolling: redraw
[    4.985117] Console: switching to colour frame buffer device 80x30
[    5.009587] uvesafb: framebuffer at 0xfd000000, mapped to 0xffffc90002000000, using 16384k, total 16384k
[    5.011422] fb0: VESA VGA frame buffer device
Starting udev
[    5.082680] udevd[122]: starting version 3.2
[    5.093330] udevd[123]: starting eudev-3.2
[    5.554953] EXT4-fs (vda): re-mounted. Opts: (null)
Populating dev cache
ALSA: Restoring mixer settings...
/usr/sbin/alsactl: load_state:1735: No soundcards found...
INIT: Entering runlevel: 5
Configuring network interfaces... done.
Starting system message bus: dbus.
Starting Connection Manager
Starting OpenBSD Secure Shell server: sshd
  generating ssh RSA key...
  generating ssh ECDSA key...
  generating ssh DSA key...
  generating ssh ED25519 key...
done.
Starting Xserver
Starting rpcbind daemon...
done.
starting statd: 
X.Org X Server 1.18.4
Release Date: 2016-07-19
X Protocol Version 11, Revision 0
Build Operating System: Linux 4.2.0-42-generic x86_64 
Current Operating System: Linux qemux86-64 4.8.0-rc4-yocto-standard #1 SMP PREEMPT Sun Sep 4 16:48:42 GMT 2016 x86_64
Kernel command line: root=/dev/vda rw highres=off  console=tty1 console=ttyS0,115200n8 printk.time=1 mem=256M ip=192.168.7.6::192.168.7.5:255.255.255.0 vga=0 uvesafb.mode_option=640x480-32 oprofile.timer=1
Build Date: 06 September 2016  10:06:15PM
 
Current version of pixman: 0.34.0
	Before reporting problems, check http://wiki.x.org
	to make sure that you have the latest version.
Markers: (--) probed, (**) from config file, (==) default setting,
	(++) from command line, (!!) notice, (II) informational,
	(WW) warning, (EE) error, (NI) not implemented, (??) unknown.
(==) Log file: "/var/log/Xorg.0.log", Time: Tue Sep  6 23:13:33 2016
(==) Using config file: "/etc/X11/xorg.conf"
(==) Using system config directory "/usr/share/X11/xorg.conf.d"
done
Starting bluetooth
bluetoothd
Starting Distributed Compiler Daemon: distcc[    6.670932] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[    6.673537] Bluetooth: BNEP filters: protocol multicast
[    6.674914] Bluetooth: BNEP socket layer initialized
.
[    6.785307] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
starting 8 nfsd kernel threads: [    6.854109] NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
[    6.879171] NFSD: starting 90-second grace period (net ffffffff81eea700)
done
starting mountd: done
Starting syslogd/klogd: done
 * Starting Avahi mDNS/DNS-SD Daemon: avahi-daemon
[A[74G[ ok ]
Starting Telephony daemon
Starting random number generator daemon.
No makedumpfile found.
Starting tcf-agent: OK
D-BUS per-session daemon address is: unix:abstract=/tmp/dbus-3JQ5emkvrJ,guid=221938c3f07e25448764149857cf4d9e
Using calibration data stored in /etc/pointercal.xinput

Poky (Yocto Project Reference Distro) 2.1+snapshot-20160906 qemux86-64 /dev/ttyS0

qemux86-64 login: Using calibration data stored in /etc/pointercal.xinput

** (process:877): WARNING **: Failed to register client: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.SessionManager was not provided by any .service files
matchbox: Cant find a keycode for keysym 269025056
matchbox: ignoring key shortcut XF86Calendar=!$contacts

matchbox: Cant find a keycode for keysym 2809
[settings daemon] Forking. run with -n to prevent fork
matchbox: ignoring key shortcut telephone=!$dates

matchbox: Cant find a keycode for keysym 269025050
matchbox: ignoring key shortcut XF86Start=!matchbox-remote -desktop

Activating service name='org.a11y.atspi.Registry'
Successfully activated service 'org.a11y.atspi.Registry'
SpiRegistry daemon is running with well-known name - org.a11y.atspi.Registry

** (matchbox-panel:914): WARNING **: Failed to load applet "battery" (/usr/lib/matchbox-panel/libbattery.so: cannot open shared object file: No such file or directory).
matchbox-wm: X error warning (0xa00003): BadWindow (invalid Window parameter) (opcode: 12)

(connman-applet:881): Gdk-CRITICAL **: gdk_window_thaw_toplevel_updates: assertion 'window->update_and_descendants_freeze_count > 0' failed
[   41.108972] hellomod: loading out-of-tree module taints kernel.
[   41.112039] Hello world!
[   41.527003] Cleaning up hellomod.
[   97.468121] python invoked oom-killer: gfp_mask=0x24280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), order=0, oom_score_adj=0
[   97.479918] python cpuset=/ mems_allowed=0
[   97.485888] CPU: 0 PID: 2127 Comm: python Tainted: G           O    4.8.0-rc4-yocto-standard #1
[   97.488697] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.9.1-0-gb3ef39f-prebuilt.qemu-project.org 04/01/2014
[   97.493468]  0000000000000000 ffff88000df2fbe0 ffffffff813d6cc2 ffff88000df2fd88
[   97.495264]  ffff88000dd45100 ffff88000df2fc48 ffffffff811956a1 ffffffff8107ecc8
[   97.497684]  ffffffff81e4c7a0 ffff88000df2fc18 ffff88000df2fc18 ffffffff8193a160
[   97.501398] Call Trace:
[   97.501896]  [<ffffffff813d6cc2>] dump_stack+0x65/0x83
[   97.506093]  [<ffffffff811956a1>] dump_header+0x5c/0x1e7
[   97.508250]  [<ffffffff8107ecc8>] ? preempt_count_add+0xa8/0xc0
[   97.509663]  [<ffffffff8193a160>] ? _raw_spin_unlock_irqrestore+0x20/0x40
[   97.511013]  [<ffffffff8113e261>] oom_kill_process+0x271/0x420
[   97.512079]  [<ffffffff81063b77>] ? has_capability_noaudit+0x17/0x20
[   97.513395]  [<ffffffff8113e64d>] out_of_memory+0x1ed/0x230
[   97.514605]  [<ffffffff81142e81>] __alloc_pages_nodemask+0xd81/0xdd0
[   97.515854]  [<ffffffff8116e173>] handle_mm_fault+0xab3/0xd30
[   97.516945]  [<ffffffff813f3017>] ? debug_smp_processor_id+0x17/0x20
[   97.518167]  [<ffffffff8104d1d9>] __do_page_fault+0x169/0x550
[   97.519237]  [<ffffffff8104d62c>] trace_do_page_fault+0x3c/0xf0
[   97.520275]  [<ffffffff8104803c>] do_async_page_fault+0x2c/0x70
[   97.521329]  [<ffffffff8193b8d8>] async_page_fault+0x28/0x30
[   97.559753] Mem-Info:
[   97.560319] active_anon:27061 inactive_anon:1100 isolated_anon:0
[   97.560319]  active_file:10218 inactive_file:10205 isolated_file:32
[   97.560319]  unevictable:0 dirty:1538 writeback:0 unstable:0
[   97.560319]  slab_reclaimable:2759 slab_unreclaimable:2330
[   97.560319]  mapped:7057 shmem:1240 pagetables:1570 bounce:0
[   97.560319]  free:2936 free_pcp:20 free_cma:0
[   97.575781] Node 0 active_anon:108244kB inactive_anon:4400kB active_file:40872kB inactive_file:35820kB unevictable:0kB isolated(anon):0kB isolated(file):128kB mapped:28228kB dirty:6152kB writeback:0kB shmem:4960kB writeback_tmp:0kB unstable:0kB pages_scanned:31068 all_unreclaimable? no
[   97.587959] DMA free:3040kB min:128kB low:160kB high:192kB active_anon:10536kB inactive_anon:0kB active_file:644kB inactive_file:1016kB unevictable:0kB writepending:1012kB present:15992kB managed:15908kB mlocked:0kB slab_reclaimable:296kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:24kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[   97.626502] lowmem_reserve[]: 0 217 217 217
[   97.643572] DMA32 free:13444kB min:1820kB low:2272kB high:2724kB active_anon:97708kB inactive_anon:4400kB active_file:40228kB inactive_file:34932kB unevictable:0kB writepending:5140kB present:245616kB managed:225552kB mlocked:0kB slab_reclaimable:10740kB slab_unreclaimable:9320kB kernel_stack:3072kB pagetables:6256kB bounce:0kB free_pcp:348kB local_pcp:348kB free_cma:0kB
[   97.654056] lowmem_reserve[]: 0 0 0 0
[   97.657530] DMA: 14*4kB (H) 6*8kB (H) 4*16kB (H) 2*32kB (H) 4*64kB (H) 2*128kB (H) 1*256kB (H) 2*512kB (H) 1*1024kB (H) 0*2048kB 0*4096kB = 3048kB
[   97.669070] DMA32: 691*4kB (UMEH) 373*8kB (UMEH) 195*16kB (UMEH) 83*32kB (UMEH) 16*64kB (UMEH) 5*128kB (UMH) 1*256kB (H) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 13444kB
[   97.675914] 20445 total pagecache pages
[   97.676499] 0 pages in swap cache
[   97.677201] Swap cache stats: add 0, delete 0, find 0/0
[   97.681756] Free swap  = 0kB
[   97.682281] Total swap = 0kB
[   97.682880] 65402 pages RAM
[   97.683377] 0 pages HighMem/MovableOnly
[   97.684095] 5037 pages reserved
[   97.684664] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents oom_score_adj name
[   97.688160] [  100]     0   100     1141       75       7       4        0             0 v86d
[   97.691493] [  123]     0   123     5483      420      15       4        0         -1000 udevd
[   97.692973] [  714]   995   714     4913      402      16       4        0             0 dbus-daemon
[   97.696067] [  721]     0   721     9627      447      27       4        0             0 connmand
[   97.697593] [  728]     0   728    10387      216      38       4        0             0 wpa_supplicant
[   97.705762] [  737]     0   737     6567      701      16       3        0         -1000 sshd
[   97.707282] [  746]     0   746     3972       91      18       4        0             0 xinit
[   97.708793] [  753]     0   753    32587     2216      88       4        0             0 Xorg
[   97.710211] [  754]   997   754     2676      396      14       4        0             0 rpcbind
[   97.715762] [  759]   994   759     4350      491      19       4        0             0 rpc.statd
[   97.717305] [  765]     0   765     4819      396      20       4        0             0 bluetoothd
[   97.722759] [  770]   996   770     6508       46      18       4        0             0 distccd
[   97.724372] [  771]   996   771     6508       46      18       4        0             0 distccd
[   97.727420] [  795]     0   795     4912      147      15       4        0             0 rpc.mountd
[   97.729232] [  809]   999   809     7546      444      28       4        0             0 avahi-daemon
[   97.734144] [  811]   999   811     7513       53      22       4        0             0 avahi-daemon
[   97.739057] [  822]     0   822     5057      334      18       4        0             0 ofonod
[   97.740780] [  825]     0   825     2890       25      10       4        0             0 rngd
[   97.745836] [  832]     0   832    13686      875      52       4        0             0 matchbox-window
[   97.747755] [  842]     0   842     7215       59      21       4        0             0 dbus-launch
[   97.753087] [  845]     0   845     9106      541      26       4        0             0 tcf-agent
[   97.755010] [  846]     0   846     4887      357      16       4        0             0 dbus-daemon
[   97.760759] [  852]     0   852     2365      219      13       4        0             0 start_getty
[   97.762471] [  853]     0   853     2365      219      13       4        0             0 start_getty
[   97.767766] [  854]     0   854     1945      181      11       4        0             0 getty
[   97.777035] [  857]     0   857     4705      903      18       4        0             0 sh
[   97.786546] [  858]     0   858     1945      181      11       4        0             0 getty
[   97.807766] [  877]     0   877    64832      664      41       4        0             0 at-spi-bus-laun
[   97.842785] [  881]     0   881    45707     3586     138       4        0             0 connman-applet
[   97.855496] [  911]     0   911     4887      503      20       4        0             0 dbus-daemon
[   97.857697] [  913]     0   913    46939     4055     144       4        0             0 matchbox-deskto
[   97.866485] [  914]     0   914    49830     4114     150       4        0             0 matchbox-panel
[   97.870250] [  915]   996   915     6508       46      18       4        0             0 distccd
[   97.881867] [  918]     0   918    11952      713      41       4        0             0 gconfd-2
[   97.897222] [  926]     0   926   140394      755      42       4        0             0 console-kit-dae
[   97.899419] [  946]     0   946    39796      543      83       4        0             0 settings-daemon
[   97.904757] [  993]     0   993    50214      550      52       4        0             0 at-spi2-registr
[   97.906571] [  994]   996   994     6508       46      18       4        0             0 distccd
[   97.913818] [ 1066]     0  1066     1945      167      11       4        0             0 syslogd
[   97.922754] [ 1067]     0  1067     1945      167      11       4        0             0 klogd
[   97.927207] [ 2124]     0  2124     6567     1076      18       3        0             0 sshd
[   97.929722] [ 2126]     0  2126     2364      220      13       4        0             0 sh
[   97.935895] [ 2127]     0  2127   230236    22137     174       5        0             0 python
[   97.937565] Out of memory: Kill process 2127 (python) score 375 or sacrifice child
[   97.950857] Killed process 2127 (python) total-vm:920944kB, anon-rss:72840kB, file-rss:15700kB, shmem-rss:8kB
[   97.969496] oom_reaper: reaped process 2127 (python), now anon-rss:4kB, file-rss:3228kB, shmem-rss:8kB

So python is using a lot of memory but what is console-kit-daemon doing?

(In reply to comment #8)
> So python is using a lot of memory but what is console-kit-daemon doing?

Looks like it requests a ton of virtual memory (why?) but isn't the real issue, its just that python took up most of the system memory and then got killed by the OOM killer. So either smart uses lots of memory or python is doing something odd occasionally but it does look memory related.

and an easy reproduer is to shrink the qemu memory size to 128MB, then the other tests work but this one always fails.

Starting to look into this...

Merge at,

http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=d3991342ede8d0db43879719c6e7b9464cd9a128