Bug 10874

This may become the bug that will target the profiling analysis which may file other bugs to reduce (optimize) the main bottlenecks.

!!!

I'll have a look tomorrow.  At least the archiver test should be trivial and this indicates a bug in the archiver.

(In reply to comment #2)
> !!!
> 
> I'll have a look tomorrow.  At least the archiver test should be trivial and
> this indicates a bug in the archiver.

Thanks Ross. 

BTW, to get profiling data per unit tests I will use something like this

http://git.yoctoproject.org/cgit/cgit.cgi/poky-contrib/commit/?h=lsandov1/oesdktest-profiling&id=bc717d33fb9e712e0e0d6343fb40f42111b856b3

So read_only_image just builds a core-image-minimal, is it possible that this was the first test to actually build an image?

(In reply to comment #4)
> So read_only_image just builds a core-image-minimal, is it possible that
> this was the first test to actually build an image?

Good question, let me check that. BTW, read_only_image builds a sato, not a minimal.

    @testcase(1435)
    def test_read_only_image(self):
        distro_features = get_bb_var('DISTRO_FEATURES')
        if not ('x11' in distro_features and 'opengl' in distro_features):
            self.skipTest('core-image-sato requires x11 and opengl in distro features')
        self.write_config('IMAGE_FEATURES += "read-only-rootfs"')
        bitbake("core-image-sato")
        # do_image will fail if there are any pending postinsts

*** Bug 10254 has been marked as a duplicate of this bug. ***

Here is some profiling data.

* sorted times (in seconds) per test case

$ sed -n -e 's/.* \(test.*\) (\(.*\)) ... OK (\(.*\)s)/\1 \2 \3/p' nightly-oe-selftest.autobuilder.log | datamash -t ' ' -g2 sum 3 | awk '{print $2, $1}' | sort -n -r
6557.767 oeqa.selftest.buildoptions.ImageOptionsTests
6107.847 oeqa.selftest.runtime-test.Postinst
4362.983 oeqa.selftest.devtool.DevtoolTests
3989.167 oeqa.selftest.sstatetests.SStateTests
3254.606 oeqa.selftest.wic.Wic
2857.417 oeqa.selftest.bbtests.BitbakeTests
1315.838 oeqa.selftest.prservice.BitbakePrTests
1308 oeqa.selftest.archiver.Archiver
1195.199 oeqa.selftest.manifest.VerifyManifest
1139.806 oeqa.selftest.imagefeatures.ImageFeatures
629.967 oeqa.selftest.recipetool.RecipetoolTests
538.316 oeqa.selftest.systemd_boot.Systemdboot
444.576 oeqa.selftest.eSDK.oeSDKExtSelfTest
374.008 oeqa.selftest.runtime-test.TestImage
365.66 oeqa.selftest.runtime-test.TestExport
343.099 oeqa.selftest.recipetool.RecipetoolAppendsrcTests
293.396 oeqa.selftest.buildoptions.SanityOptionsTest
268.011 oeqa.selftest.buildoptions.BuildhistoryTests
255.04 oeqa.selftest.signing.Signing
236.454 oeqa.selftest.bblayers.BitbakeLayers
221.433 oeqa.selftest.oescripts.TestScripts
142.181 oeqa.selftest.pkgdata.OePkgdataUtilTests
134.103 oeqa.selftest.oescripts.BuildhistoryDiffTests
126.501 oeqa.selftest.buildoptions.ArchiverTest
98.752 oeqa.selftest.buildoptions.DiskMonTest
70.753 oeqa.selftest.layerappend.LayerAppendTests
50.305 oeqa.selftest.signing.LockedSignatures
28.792 oeqa.selftest.liboe.LibOE
23.9 oeqa.selftest.tinfoil.TinfoilTests
18.349 oeqa.selftest.lic-checksum.LicenseTests
15.812 oeqa.selftest.image_typedep.ImageTypeDepTests
0.011 oeqa.selftest.oelib.path.TestRealPath
0 oeqa.selftest.oelib.utils.TestTrimVersion
0 oeqa.selftest.oelib.utils.TestPackagesFilterOutSystem
0 oeqa.selftest.oelib.types.TestList
0 oeqa.selftest.oelib.types.TestBooleanType
0 oeqa.selftest.oelib.license.TestSingleLicense
0 oeqa.selftest.oelib.license.TestSimpleCombinations
0 oeqa.selftest.oelib.elf.TestElf

* top-10 oe-selftest consuming most time

sed -n -e 's/.* \(test.*\) (\(.*\)) ... OK (\(.*\)s)/\1 \2 \3/p' nightly-oe-selftest.autobuilder.log | awk '{print $3, $2, $1}' | sort -n -r | head
5947.529 oeqa.selftest.runtime-test.Postinst test_postinst_roofs_and_boot
3765.832 oeqa.selftest.buildoptions.ImageOptionsTests test_read_only_image
1989.198 oeqa.selftest.buildoptions.ImageOptionsTests test_ccache_tool
1974.684 oeqa.selftest.wic.Wic test_alternate_output_dir
1606.850 oeqa.selftest.bbtests.BitbakeTests test_non_gplv3
1308.000 oeqa.selftest.archiver.Archiver test_archiver_allows_to_filter_on_recipe_name
1173.233 oeqa.selftest.manifest.VerifyManifest test_SDK_manifest_entries
802.737 oeqa.selftest.buildoptions.ImageOptionsTests test_incremental_image_generation
566.259 oeqa.selftest.sstatetests.SStateTests test_sstate_cache_management_script_using_machine
550.060 oeqa.selftest.devtool.DevtoolTests test_devtool_add_library

log obtained from AB [1]

[1] https://autobuilder.yoctoproject.org/main/builders/nightly-oe-selftest/builds/807

Two series are intended to reduce the cpu time considerably [1] [2] but there is still room for improvement, specially including the sstate mirrors, but the later is block by bug 10929.

[1] http://lists.openembedded.org/pipermail/openembedded-core/2017-January/132088.html

[2] http://lists.openembedded.org/pipermail/openembedded-core/2017-January/131986.html

There have been several patches targeting optimizations sent (and most merged) during M3 so we should check again the numbers after the M3 release, so moving it to M4.

I've filed a specific bug 11233 for test_archiver_allows_to_filter_on_recipe_name because I don't think it was fixed. Still seems to (at least sometimes) take over 8 minutes to finish.

Almost current top 20 (March 3rd, https://autobuilder.yocto.io/builders/nightly-oe-selftest/builds/200):
2656.240 oeqa.selftest.runtime-test.Postinst test_postinst_roofs_and_boot
890.481 oeqa.selftest.wic.Wic test_bmap_long
708.996 oeqa.selftest.buildoptions.ImageOptionsTests test_read_only_image
575.632 oeqa.selftest.buildoptions.ImageOptionsTests test_ccache_tool
569.475 oeqa.selftest.manifest.VerifyManifest test_SDK_manifest_entries
484.100 oeqa.selftest.bbtests.BitbakeTests test_non_gplv3
263.932 oeqa.selftest.imagefeatures.ImageFeatures test_clutter_image_can_be_built
262.426 oeqa.selftest.wic.Wic test_iso_image
259.397 oeqa.selftest.systemd_boot.Systemdboot test_efi_systemdboot_images_can_be_built
253.061 oeqa.selftest.bbtests.BitbakeTests test_continue
249.166 oeqa.selftest.devtool.DevtoolTests test_devtool_add_library
243.201 oeqa.selftest.archiver.Archiver test_archiver_allows_to_filter_on_recipe_name
229.400 oeqa.selftest.devtool.DevtoolTests test_devtool_modify_native
215.134 oeqa.selftest.runtime-test.TestImage test_testimage_install
187.150 oeqa.selftest.buildoptions.ImageOptionsTests test_incremental_image_generation
180.311 oeqa.selftest.sstatetests.SStateTests test_sstate_cache_management_script_using_pr_3
172.013 oeqa.selftest.devtool.DevtoolTests test_devtool_build_image
167.931 oeqa.selftest.devtool.DevtoolTests test_devtool_deploy_target
149.136 oeqa.selftest.imagefeatures.ImageFeatures test_wayland_support_in_image
136.856 oeqa.selftest.wic.Wic test_qemu

(the very latest runs have test_devtool_virtual_kernel_modify taking 8 hours alone but that's at least partly a kernel cloning issue)

Updating the top 10 list with a current build

curl -s https://autobuilder.yoctoproject.org/main/builders/nightly-oe-selftest/builds/870/steps/Running%20oe-selftest/logs/stdio/text | sed -n -e 's/.* \(test.*\) (\(.*\)) ... OK (\(.*\)s)/\1 \2 \3/p' | awk '{print $3, $2, $1}' | sort -n -r | head

5344.897 oeqa.selftest.runtime-test.Postinst test_postinst_rootfs_and_boot
3078.308 oeqa.selftest.buildoptions.ImageOptionsTests test_ccache_tool
1353.179 oeqa.selftest.devtool.DevtoolTests test_devtool_virtual_kernel_modify
770.546 oeqa.selftest.devtool.DevtoolTests test_devtool_build_image
753.150 oeqa.selftest.imagefeatures.ImageFeatures test_clutter_image_can_be_built
658.208 oeqa.selftest.signing.Signing test_signing_packages
639.644 oeqa.selftest.archiver.Archiver test_archiver_allows_to_filter_on_recipe_name
560.257 oeqa.selftest.devtool.DevtoolTests test_devtool_buildclean
547.177 oeqa.selftest.wic.Wic test_iso_image
541.583 oeqa.selftest.manifest.VerifyManifest test_SDK_manifest_entries

the build taken was built and has the commit id:

Apr 11 20:51 	b283b10d5363... 	success 	#870 	Build successful

taken from https://autobuilder.yoctoproject.org/main/builders/nightly-oe-selftest

This is an umbrella bug and all its dependencies where completed so resolving it as fixed.

In the other hand, there are two main actions that have impact the building times, reducing these considerably:

1. share states are **now** being used in the autobuilder directly impacting the building times. 

2. early  2.5 M1, what is being proposed at bug 10033 (oe-selftest parallelization) will greatly impact the times (local tests indicated the complete oe-selftest execution runs in less than an hour)