14773 2022-03-31 20:11:21 +0000 AB-INT: prservice.BitbakePrTests.test_import_export_replace_db Failure expanding variable 2022-04-13 21:52:24 +0000 1 1 10 QA/Testing Functional (self) Testing oe-selftest unspecified x86 Multiple RESOLVED FIXED AB-INT Medium normal 4.1 1 alexandre.belloni richard.purdie alexandre.belloni richard.purdie --- --- No (bug/feature does not impact docs) oldest_to_newest 92907 0 alexandre.belloni 2022-03-31 20:11:21 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/86/builds/3325/steps/14/logs/stdio oe-selftest-fedora fedora34-ty-1 2022-03-27 04:39:57,068 - oe-selftest - INFO - ====================================================================== 2022-03-27 04:39:57,069 - oe-selftest - INFO - FAIL: prservice.BitbakePrTests.test_import_export_replace_db (subunit.RemotedTestCase) 2022-03-27 04:39:57,069 - oe-selftest - INFO - ---------------------------------------------------------------------- 2022-03-27 04:39:57,069 - oe-selftest - INFO - testtools.testresult.real._StringException: Traceback (most recent call last): File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/selftest/cases/prservice.py", line 95, in test_import_export_replace_db self.run_test_pr_export_import('m4') File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/selftest/cases/prservice.py", line 87, in run_test_pr_export_import self.assertEqual(import_result.status, 0, msg="PR Service database import failed: %s" % import_result.output) File "/usr/lib64/python3.9/unittest/case.py", line 837, in assertEqual assertion_func(first, second, msg=msg) File "/usr/lib64/python3.9/unittest/case.py", line 830, in _baseAssertEqual raise self.failureException(msg) AssertionError: 1 != 0 : PR Service database import failed: NOTE: Started PRServer with DBfile: /home/pokybuild/yocto-worker/oe-selftest-fedora/build/build-st-2926744/cache/prserv.sqlite3, Address: 127.0.0.1:36081, PID: 780141 Loading cache...done. Loaded 0 entries from dependency cache. Parsing recipes...WARNING: /home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/recipes-core/images/core-image-minimal-mtdutils.bb: Exception during build_dependencies for do_rootfs WARNING: /home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/recipes-core/images/core-image-minimal-mtdutils.bb: Error during finalise of /home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/recipes-core/images/core-image-minimal-mtdutils.bb ERROR: ExpansionError during parsing /home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/recipes-core/images/core-image-minimal-mtdutils.bb Traceback (most recent call last): File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oe/rootfs.py", line 6, in <module>: from oe.utils import execute_pre_post_process >from oe.package_manager import * from oe.manifest import * File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oe/package_manager/__init__.py", line 17, in <module>: import string >from oe.gpg_sign import get_signer import hashlib File "<frozen importlib._bootstrap>", line 1004, in _find_and_load(name='oe.gpg_sign', import_=<built-in function __import__>) File "<frozen importlib._bootstrap>", line 158, in _ModuleLockManager.__enter__() File "<frozen importlib._bootstrap>", line 110, in _ModuleLock.acquire() bb.data_smart.ExpansionError: Failure expanding variable do_rootfs[vardeps], expression was PACKAGE_FEED_URIS PACKAGE_FEED_BASE_PATHS PACKAGE_FEED_ARCHS ${@rootfs_variables(d)} which triggered exception KeyError: 139622474778432 The variable dependency chain for the failure is: do_rootfs[vardeps] ERROR: Parsing halted due to errors, see error messages above 92913 1 richard.purdie 2022-04-01 10:06:51 +0000 This was a routine master build, RP's sys.modules fixes were not present. https://bugs.python.org/issue43546 has similarities and the comment: """ It looks like method _ModuleLock.acquire() was re-entered in the same thread. * Enter acquire() first time, set _blocking_on[tid]. * Trigger some callback (profiler, debugger, tracemalloc) which uses import and calls acquire() again from the same thread. * Enter acquire() second time, set _blocking_on[tid]. * Delete _blocking_on[tid] and leave the second acquire(). * Try to leave the first acquire() and delete _blocking_on[tid] again. """ is similar. We've also see this in memres bitbake testing: https://autobuilder.yoctoproject.org/typhoon/#/builders/79/builds/3382/steps/15/logs/stdio which is in oe.data and in the OE_IMPORTS instead of oe,gpg_sign in a different import location. 92920 2 richard.purdie 2022-04-01 20:30:52 +0000 The second traceback, different code but probably the same issue: File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/selftest/cases/signing.py", line 72, in test_signing_packages self.setup_gpg() File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/selftest/cases/signing.py", line 32, in setup_gpg nsysroot = get_bb_var("RECIPE_SYSROOT_NATIVE", "gnupg-native") File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/utils/commands.py", line 281, in get_bb_var return get_bb_vars([var], target, postconfig)[var] File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/utils/commands.py", line 243, in get_bb_vars bbenv = get_bb_env(target, postconfig=postconfig) File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/utils/commands.py", line 237, in get_bb_env return bitbake("-e %s" % target, postconfig=postconfig).output File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/utils/commands.py", line 229, in bitbake return runCmd(cmd, ignore_status, timeout, output_log=output_log, **options) File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/lib/oeqa/utils/commands.py", line 207, in runCmd raise AssertionError("Command '%s' returned non-zero exit status %d:\n%s" % (command, result.status, exc_output)) AssertionError: Command 'bitbake -e gnupg-native' returned non-zero exit status 1: NOTE: Reconnecting to bitbake server... ERROR: Unable to parse Var <OE_IMPORTED[:=]> Traceback (most recent call last): File "Var <OE_IMPORTED[:=]>", line 1, in <module> File "/home/pokybuild/yocto-worker/oe-selftest-centos/build/meta/classes/base.bbclass", line 30, in oe_import(d=<bb.data_smart.DataSmart object at 0x7fba6a689760>): # Make a python object accessible from the metadata > bb.utils._context[toimport.split(".", 1)[0]] = __import__(toimport) except AttributeError as e: File "<frozen importlib._bootstrap>", line 1004, in _find_and_load(name='oe.path', import_=<built-in function __import__>) File "<frozen importlib._bootstrap>", line 158, in _ModuleLockManager.__enter__() File "<frozen importlib._bootstrap>", line 110, in _ModuleLock.acquire() bb.data_smart.ExpansionError: Failure expanding variable OE_IMPORTED[:=], expression was ${@oe_import(d)} which triggered exception KeyError: 140438942700992 The variable dependency chain for the failure is: OE_IMPORTED[:=] 92921 3 richard.purdie 2022-04-01 20:31:11 +0000 https://bugs.python.org/issue47195 92922 4 richard.purdie 2022-04-02 09:10:20 +0000 https://autobuilder.yoctoproject.org/typhoon/#/builders/86/builds/3358/steps/14/logs/stdio File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/selftest/cases/devtool.py", line 1363, in test_devtool_deploy_target machine = get_bb_var('MACHINE') File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/utils/commands.py", line 281, in get_bb_var return get_bb_vars([var], target, postconfig)[var] File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/utils/commands.py", line 243, in get_bb_vars bbenv = get_bb_env(target, postconfig=postconfig) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/utils/commands.py", line 239, in get_bb_env return bitbake("-e", postconfig=postconfig).output File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/utils/commands.py", line 229, in bitbake return runCmd(cmd, ignore_status, timeout, output_log=output_log, **options) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/lib/oeqa/utils/commands.py", line 207, in runCmd raise AssertionError("Command '%s' returned non-zero exit status %d:\n%s" % (command, result.status, exc_output)) AssertionError: Command 'bitbake -e' returned non-zero exit status 1: NOTE: Reconnecting to bitbake server... WARNING: File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/bin/bitbake-server", line 52, in <module> bb.server.process.execServer(lockfd, readypipeinfd, lockname, sockname, timeout, xmlrpcinterface) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/server/process.py", line 558, in execServer server.run() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/server/process.py", line 110, in run ret = self.main() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/server/process.py", line 219, in main self.command_channel_reply.send(self.cooker.command.runCommand(command)) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/command.py", line 89, in runCommand self.cooker.updateCacheSync() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cooker.py", line 1643, in updateCacheSync self.initConfigurationData() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cooker.py", line 407, in initConfigurationData self.databuilder.parseBaseConfiguration() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cookerdata.py", line 267, in parseBaseConfiguration self.data = self.parseConfigurationFiles(self.prefiles, self.postfiles) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cookerdata.py", line 452, in parseConfigurationFiles data = _inherit(bbclass, data) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cookerdata.py", line 162, in wrapped return func(fn, *args) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cookerdata.py", line 191, in _inherit bb.parse.BBHandler.inherit(bbclass, "configuration INHERITs", 0, data) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/parse_py/BBHandler.py", line 63, in inherit include(fn, file, lineno, d, "inherit") File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/parse_py/ConfHandler.py", line 67, in include include_single_file(parentfn, fn, lineno, data, error_out) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/parse_py/ConfHandler.py", line 90, in include_single_file bb.parse.handle(fn, data, True) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/__init__.py", line 107, in handle return h['handle'](fn, data, include) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/parse_py/BBHandler.py", line 124, in handle statements.eval(d) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/ast.py", line 19, in eval statement.eval(data) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/parse/ast.py", line 117, in eval val = e.expand(groupd["value"], key + "[:=]") File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/data_smart.py", line 477, in expand return self.expandWithRefs(s, varname).value File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/data_smart.py", line 454, in expandWithRefs s = __expand_python_regexp__.sub(varparse.python_sub, s) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/data_smart.py", line 144, in python_sub value = utils.better_eval(codeobj, DataContext(self.d), {'d' : self.d}) File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/utils.py", line 429, in better_eval return eval(source, ctx, locals) File "Var <OE_IMPORTED[:=]>", line 1, in <module> File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/classes/base.bbclass", line 26, in oe_import import oe.data File "<frozen importlib._bootstrap>", line 1024, in _find_and_load File "<frozen importlib._bootstrap>", line 171, in __enter__ File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cooker.py", line 168, in acquire return orig_acquire(self) File "<frozen importlib._bootstrap>", line 110, in acquire File "/usr/lib64/python3.10/asyncio/base_events.py", line 685, in __del__ _warn(f"unclosed event loop {self!r}", ResourceWarning, source=self) File "/usr/lib64/python3.10/warnings.py", line 112, in _showwarnmsg _showwarnmsg_impl(msg) File "/usr/lib64/python3.10/warnings.py", line 28, in _showwarnmsg_impl text = _formatwarnmsg(msg) File "/usr/lib64/python3.10/warnings.py", line 128, in _formatwarnmsg return _formatwarnmsg_impl(msg) File "/usr/lib64/python3.10/warnings.py", line 56, in _formatwarnmsg_impl import tracemalloc File "<frozen importlib._bootstrap>", line 1024, in _find_and_load File "<frozen importlib._bootstrap>", line 171, in __enter__ File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cooker.py", line 167, in acquire bb.warn("\n".join(traceback.format_stack())) ERROR: Unable to parse Var <OE_IMPORTED[:=]> Traceback (most recent call last): File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/meta/classes/base.bbclass", line 26, in oe_import(d=<bb.data_smart.DataSmart object at 0x7fe4723c5270>): > import oe.data for toimport in oe.data.typed_value("OE_IMPORTS", d): File "<frozen importlib._bootstrap>", line 1024, in _find_and_load(name='oe.data', import_=<built-in function __import__>) File "<frozen importlib._bootstrap>", line 171, in _ModuleLockManager.__enter__() File "/home/pokybuild/yocto-worker/oe-selftest-fedora/build/bitbake/lib/bb/cooker.py", line 168, in _ModuleLock.acquire(): bb.warn("\n".join(traceback.format_stack())) > return orig_acquire(self) File "<frozen importlib._bootstrap>", line 123, in _ModuleLock.acquire() bb.data_smart.ExpansionError: Failure expanding variable OE_IMPORTED[:=], expression was ${@oe_import(d)} which triggered exception KeyError: 140619389032256 The variable dependency chain for the failure is: OE_IMPORTED[:=] which shows us it is from a warning in garbage collection from asycio 93045 5 richard.purdie 2022-04-13 21:52:24 +0000 https://git.yoctoproject.org/poky/commit/?id=496cbc01ca0ffd2b582b9ab4c4e0f54db7b18b00 https://git.yoctoproject.org/poky/commit/?id=b868387c425cca35c06179b90d44422fbaf2a9ab