11275 2017-03-31 09:56:45 +0000 tinfoil: some output gets duplicated 2017-09-01 00:10:53 +0000 1 1 7 Build System, Metadata & Runtime BitBake bitbake unspecified x86 Multiple RESOLVED FIXED Backport to 2.3.1 ? Medium+ normal 2.4 M4 1 patrick.ohly bluelightning bluelightning poky.bs.watcher poky.watcher richard.purdie --- --- No (bug/feature does not impact docs) oldest_to_newest 71950 0 patrick.ohly 2017-03-31 09:56:45 +0000 Output produced by the bitbake server (for example, bb.note() messages) gets printed twice in a tinfoil application, even with current bitbake master-next. Example application "parse-recipes.py": #!/usr/bin/python3 import os import sys import logging # Allow importing lib modules lib_path = os.path.abspath(os.path.dirname(os.path.realpath(__file__)) + '/../lib') sys.path.insert(0, lib_path) # look for bitbake/bin dir in PATH bitbakepath = None for pth in os.environ['PATH'].split(':'): if os.path.exists(os.path.join(pth, '../lib/bb')): bitbakepath = os.path.abspath(os.path.join(pth, '..')) break if bitbakepath: sys.path.insert(0, bitbakepath + '/lib') else: print("ERROR: bitbake not found in PATH. This script must be called after setting up a bitbake build environment.", file=sys.stderr) exit(1) import bb.tinfoil import bb with bb.tinfoil.Tinfoil() as tinfoil: # Increase logging from tinfoil and use the logger. logger = tinfoil.logger tinfoil.logger.setLevel(logging.INFO) # Both of these messages appear only once. logger.info('logger.info: foo') bb.note('bb.note: bar') # But any bb.note or bb.warn from a recipe appears twice. tinfoil.prepare(config_only=False) Modified OE-core to trigger a message: diff --git a/meta/recipes-extended/ethtool/ethtool_4.8.bb b/meta/recipes-extended/ethtool/ethtool_4.8.bb index 4ca88d766c6..ef153164335 100644 --- a/meta/recipes-extended/ethtool/ethtool_4.8.bb +++ b/meta/recipes-extended/ethtool/ethtool_4.8.bb @@ -28,3 +28,6 @@ do_install_ptest () { install ${B}/ethtool ${D}${PTEST_PATH}/ethtool sed -i 's/^Makefile/_Makefile/' ${D}${PTEST_PATH}/Makefile } +python () { + bb.note('ethtool getting parsed') +} Output okay in bitbake, not okay in the test app: $ rm -rf cache/ tmp-glibc/cache/ $ parse-recipes.py NOTE: logger.info: foo NOTE: bb.note: bar NOTE: ethtool getting parsed########################################################################### | ETA: 0:00:03 NOTE: /fast/work/intel-iot-refkit/openembedded-core/meta/recipes-extended/ethtool/ethtool_4.8.bb: ethtool getting parsed NOTE: /fast/work/intel-iot-refkit/openembedded-core/meta/recipes-extended/ethtool/ethtool_4.8.bb: ethtool getting parsed Parsing recipes: 100% |#################################################################################################| Time: 0:00:23 Parsing of 2174 .bb files complete (0 cached, 2174 parsed). 3017 targets, 455 skipped, 0 masked, 0 errors. Summary: There was 1 WARNING message shown. $ rm -rf cache/ tmp-glibc/cache/ $ bitbake -g ethtool NOTE: /fast/work/intel-iot-refkit/openembedded-core/meta/recipes-extended/ethtool/ethtool_4.8.bb: ethtool getting parsed| ETA: 0:00:03 Parsing recipes: 100% |#################################################################################################| Time: 0:00:23 Parsing of 2174 .bb files complete (0 cached, 2174 parsed). 3017 targets, 455 skipped, 0 masked, 0 errors. NOTE: Resolving any missing task queue dependencies NOTE: PN build list saved to 'pn-buildlist' NOTE: Task dependencies saved to 'task-depends.dot' NOTE: Flatened recipe dependencies saved to 'recipe-depends.dot' Summary: There was 1 WARNING message shown. 71951 1 patrick.ohly 2017-03-31 09:59:14 +0000 Note that the "ethtool getting parsed" actually gets printed three times, once without the ".../ethtool/ethtool_4.8.bb: " prefix, twice with it. The one without prefix overlaps poorly with the progress bar. 71952 2 bluelightning 2017-03-31 10:11:12 +0000 Another side-effect of my recent change, I'm afraid :( 73288 3 bluelightning 2017-05-16 22:01:01 +0000 To give a more complete explanation, this was a side-effect of http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=542eb4731cd491c23e30689e5c8c0da91ba4bb44. At the moment I'm not sure of a solution that allows us to see the timeout messages without duplicating others, but I'm working on it. 73990 4 bluelightning 2017-06-12 15:34:18 +0000 Fixes merged to master: http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=d44d5a2e79affce73750561c1e1ca58f8fcb7bb1 http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=55c4781cdef853480d9e9d94f5aee26c512777c3 76072 5 bluelightning 2017-08-23 03:46:29 +0000 This issue has unfortunately returned - after the recent server rework we again saw messages going missing so I had to revert d44d5a2e79affce73750561c1e1ca58f8fcb7bb1. I am currently testing a fix which should be ready for M4. 76432 6 bluelightning 2017-09-01 00:10:53 +0000 Fix merged to master: http://git.yoctoproject.org/cgit/cgit.cgi/poky/commit/?id=6ef0a567706be050c65efcebf444510c0969ce89