Bug 10826

Below warning is displayed before the test are executed, seems like this is why the test is failing 

2016-12-20 18:57:44,460 - selftest.base - WARNING - tearDown commands have failed: bitbake-layers remove-layer */workspace

It's more likely that the teardown commands fail because of the error within the test rather than causing it.

Created attachment 3573 [details]
log of failure in master

Created attachment 3574 [details]
log of working correctly on morty

Some additional information:

- I executed devtool module manually on my local machine debain 8 and in a remote server OpenSuse421 and was working correctly 
- When executing devtool module on buildslaves of GDC ABs are working correctly 
- When executing buildset "nightly-oe-selftest" on morty branch on GDC AB is working (commit 7c3a47ed8965c3a3eb90a9a4678d5caedbba6337)

I have suggested José to run a branch with all the tests but the first one that fails to try to see if this is a one-test that breaks up the rest of the execution.

I tested a branch excluding "devtool_deploy_target" and the ERROR appears in another test case this was "test_all_users_can_connect_via_ssh_without_password" log is attached.

Created attachment 3576 [details]
log excluding test case previously failed

I tried to reproduce this error in my setup and I was not able to see it. I'm looping the tests to see if I get the error later.

I tested a branch without test that are calling "runqemu" and see the failure again but now in a testcase of tinfoil "test_expand (oeqa.selftest.tinfoil.TinfoilTests)" log attached

Created attachment 3577 [details]
Log of failure present when running without test cases using runqemu

On a manual run, I got the following failures & errors. Nothing conclusive yet.

lsandov1@yctb05:~/high/10826> egrep 'FAIL \( |ERROR \(' manual-oe-selftest-ubuntu1404
2016-12-27 07:55:49 -   test_expand (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (20.541s)
2016-12-27 07:56:09 -   test_getvar (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.230s)
2016-12-27 07:56:10 -   test_getvar_bb_origenv (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.244s)
2016-12-27 07:56:10 -   test_list_recipes (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.190s)
2016-12-27 07:56:10 -   test_parse_recipe (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.188s)
2016-12-27 07:56:10 -   test_parse_recipe_copy_expand (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.248s)
2016-12-27 07:56:10 -   test_parse_recipe_initial_datastore (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.188s)
2016-12-27 07:56:11 -   test_setvariable_clean (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.260s)
2016-12-27 07:56:11 -   test_wait_event (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.182s)
lsandov1@yctb05:~/high/10826> egrep 'FAIL \(|ERROR \(' manual-oe-selftest-ubuntu1404
2016-12-27 05:22:11 -   test_devtool_add_fetch_git (oeqa.selftest.devtool.DevtoolTests) ... FAIL (11.034s)
2016-12-27 05:23:00 -   test_devtool_add_library (oeqa.selftest.devtool.DevtoolTests) ... FAIL (6.005s)
2016-12-27 05:47:52 -   test_devtool_upgrade_git (oeqa.selftest.devtool.DevtoolTests) ... FAIL (21.101s)
2016-12-27 06:36:21 -   test_recipetool_load_plugin (oeqa.selftest.recipetool.RecipetoolTests) ... FAIL (18.475s)
2016-12-27 07:55:49 -   test_expand (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (20.541s)
2016-12-27 07:56:09 -   test_getvar (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.230s)
2016-12-27 07:56:10 -   test_getvar_bb_origenv (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.244s)
2016-12-27 07:56:10 -   test_list_recipes (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.190s)
2016-12-27 07:56:10 -   test_parse_recipe (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.188s)
2016-12-27 07:56:10 -   test_parse_recipe_copy_expand (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.248s)
2016-12-27 07:56:10 -   test_parse_recipe_initial_datastore (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.188s)
2016-12-27 07:56:11 -   test_setvariable_clean (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.260s)
2016-12-27 07:56:11 -   test_wait_event (oeqa.selftest.tinfoil.TinfoilTests) ... ERROR (0.182s)
2016-12-27 07:56:11 -   test_bmap (oeqa.selftest.wic.Wic) ... FAIL (1.893s)
2016-12-27 07:56:13 -   test_build_artifacts (oeqa.selftest.wic.Wic) ... FAIL (0.896s)
2016-12-27 07:56:14 -   test_build_image_name (oeqa.selftest.wic.Wic) ... FAIL (1.201s)
2016-12-27 07:56:15 -   test_compress_bzip2 (oeqa.selftest.wic.Wic) ... FAIL (1.215s)
2016-12-27 07:56:16 -   test_compress_gzip (oeqa.selftest.wic.Wic) ... FAIL (1.217s)
2016-12-27 07:56:18 -   test_compress_xz (oeqa.selftest.wic.Wic) ... FAIL (1.156s)
2016-12-27 07:56:19 -   test_createhelp (oeqa.selftest.wic.Wic) ... FAIL (1.380s)
2016-12-27 07:56:20 -   test_directdisk_bootloader_config (oeqa.selftest.wic.Wic) ... FAIL (1.236s)
2016-12-27 07:56:21 -   test_gpt_image (oeqa.selftest.wic.Wic) ... FAIL (1.327s)
2016-12-27 07:56:23 -   test_help (oeqa.selftest.wic.Wic) ... FAIL (1.033s)
2016-12-27 07:56:24 -   test_help_kickstart (oeqa.selftest.wic.Wic) ... FAIL (1.211s)
2016-12-27 07:56:25 -   test_help_overview (oeqa.selftest.wic.Wic) ... FAIL (1.187s)
2016-12-27 07:56:26 -   test_help_plugins (oeqa.selftest.wic.Wic) ... FAIL (1.328s)
2016-12-27 07:56:27 -   test_image_env (oeqa.selftest.wic.Wic) ... FAIL (1.215s)
2016-12-27 07:56:29 -   test_iso_image (oeqa.selftest.wic.Wic) ... FAIL (1.211s)
2016-12-27 07:56:30 -   test_listhelp (oeqa.selftest.wic.Wic) ... FAIL (0.920s)
2016-12-27 07:56:31 -   test_mkefidisk (oeqa.selftest.wic.Wic) ... FAIL (1.203s)
2016-12-27 07:56:32 -   test_mkgummidisk (oeqa.selftest.wic.Wic) ... FAIL (1.314s)
2016-12-27 07:56:33 -   test_no_command (oeqa.selftest.wic.Wic) ... FAIL (1.281s)
2016-12-27 07:56:35 -   test_qemux86_directdisk (oeqa.selftest.wic.Wic) ... FAIL (1.328s)
2016-12-27 07:56:36 -   test_rootfs_artifacts (oeqa.selftest.wic.Wic) ... FAIL (1.101s)
2016-12-27 07:56:37 -   test_rootfs_indirect_recipes (oeqa.selftest.wic.Wic) ... FAIL (1.276s)
2016-12-27 07:56:38 -   test_sdimage_bootpart (oeqa.selftest.wic.Wic) ... FAIL (0.887s)
2016-12-27 07:56:39 -   test_systemd_bootdisk (oeqa.selftest.wic.Wic) ... FAIL (0.914s)
2016-12-27 07:56:40 -   test_unsupported_subcommand (oeqa.selftest.wic.Wic) ... FAIL (1.186s)
2016-12-27 07:56:41 -   test_wic_image_type (oeqa.selftest.wic.Wic) ... FAIL (1.300s)
2016-12-27 07:56:43 -   test_wrong_compressor (oeqa.selftest.wic.Wic) ... FAIL (1.107s)
2016-12-27 07:56:44 -   test_efi_gummiboot_images_can_be_built (oeqa.selftest.gummiboot.Gummiboot) ... FAIL (1.517s)
2016-12-27 07:56:45 -   test_wic_command_can_create_efi_gummiboot_installation_images (oeqa.selftest.gummiboot.Gummiboot) ... FAIL (1.244s)
2016-12-27 07:56:46 -   test_efi_systemdboot_images_can_be_built (oeqa.selftest.systemd_boot.Systemdboot) ... FAIL (1.343s)
lsandov1@yctb05:~/high/10826>

(In reply to comment #12)
> On a manual run, I got the following failures & errors. Nothing conclusive
> yet.

This run was done base on 

commit 573c646d4cc62dcd0c230381df4940bdf314d495
Author: Ross Burton <ross.burton@intel.com>
Date:   Wed Dec 14 19:53:46 2016 +0000

    bitbake: BBHandler: use with instead of open/close

    This is more pythonic and can handle unclosed file warnings better
    than the previous code structure.

which is around 100 behind current HEAD. Also, it had some local commits that I did not noticed. So running again using latest master:

commit dbb247cac5fbf7b037e4955f9793828451723924
Author: Richard Purdie <richard.purdie@linuxfoundation.org>
Date:   Tue Dec 20 19:02:11 2016 +0000

    bitbake: cookerdata: Convert multiconfig to use BB_CURRENT_MC

With current's master HEAD (dbb247cac5fbf7b037e4955f9793828451723924), the GDC AB fail in the first test

======================================================================
ERROR [439.311s]: test_all_users_can_connect_via_ssh_without_password (oeqa.selftest.imagefeatures.ImageFeatures)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/main.py", line 520, in setup_bitbake
    server_connection = server.establishConnection(featureset)
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/server/process.py", line 287, in establishConnection
    _, error = self.connection.connection.runCommand(["setFeatures", featureset])
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/server/process.py", line 61, in runCommand
    bb.fatal("Gave up; Too many tries: timeout while attempting to communicate with bitbake server")
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/__init__.py", line 104, in fatal
    raise BBHandledException()
bb.BBHandledException



During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/meta/lib/oeqa/utils/decorators.py", line 109, in wrapped_f
    return func(*args, **kwargs)
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/meta/lib/oeqa/selftest/imagefeatures.py", line 59, in test_all_users_can_connect_via_ssh_without_password
    with runqemu("core-image-minimal") as qemu:
  File "/usr/lib/python3.4/contextlib.py", line 59, in __enter__
    return next(self.gen)
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/meta/lib/oeqa/utils/commands.py", line 227, in runqemu
    tinfoil.prepare(config_only=False, quiet=True)
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/tinfoil.py", line 210, in prepare
    extrafeatures)
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/main.py", line 522, in setup_bitbake
    bb.fatal("Could not connect to server %s: %s" % (configParams.remote_server, str(e)))
  File "/home/ab/autobuilder/yocto-worker/nightly-oe-selftest-ubuntu1404/build/bitbake/lib/bb/__init__.py", line 104, in fatal
    raise BBHandledException()
bb.BBHandledException

----------------------------------------------------------------------
Ran 1 test in 439.393s

From now on, I will try to file a build similar to [1] on the GDC AB infraestructure which is actually what Jose was doing at the beginning.


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

I'm proposing this bug as M+ based on the following facts:
- there are no manifestations of it out of the GDC AB. First suspect is the GDC AB itself.

  - I ran iterations of a test that fails in the GDC AB in my machine and it hasn't failed.

  - the main AB does not show any error instance of the type.

- It is a M+ because we still don't know why it fails. First suspect is tinfoil-2.

  - previous to the TF2 changes the GDC AB does not show the failure

  - setting breakpoints around the failure area provoke the failure to manifest in different ways, could be a race condition on the bitbake server setup.

  - runqemu is out of the suspect list as everything about the failure is happening after tinfoil.prepare()

In debugging with Alejandro Hernandez and Saul we found that this bug is reproducible on any machine with a setting of:

PRSERV_HOST = "localhost:0"

At the conf/local.conf or any other conf file. Still need to investigate why the PR server is down in the GDC AB.

I have reproduced this issue in 2 of my machines, a Fedora 25 and an opensuse 42.1. I have written the procedure in bug 10866. A workaround for the issue is described there.

Another workaround that Alejandro and I tested in the GDC AB is to omit the PRSERV_HOST, all the workers tested (ubuntu, opensuse, fedora and debian) show a pass as expected.

returning this bug to High waiting for the CCB approval as per the process.

http://git.yoctoproject.org/cgit.cgi/poky/commit/?id=9f6a1043f68580ed9604e750fd0f993f933bb66e fixes 10866 at least.

(In reply to comment #19)
> http://git.yoctoproject.org/cgit.cgi/poky/commit/
> ?id=9f6a1043f68580ed9604e750fd0f993f933bb66e fixes 10866 at least.

I verified this one works. Once bug 10873 is closed, this bug can be closed too.

Created attachment 3597 [details]
verification that selftest finishes execution on today's master

See the verification log attached that selftest finishes execution on today's master. Tested in the GDC Autobuilder.