Bug 9693

Summary: oeqa/selftest/recipetool: runCmd's output is populated with previous output
Product: [QA/Testing] Build Testing Reporter: Leonardo Sandoval Gonzalez <leonardo.sandoval.gonzalez>
Component: generalAssignee: Leonardo Sandoval Gonzalez <leonardo.sandoval.gonzalez>
Status: RESOLVED OBSOLETE QA Contact:
Severity: minor    
Priority: Medium CC: benjamin.esquivel, eduard.bartosh, joshuagloe, juro.bystricky, richard.purdie
Version: 2.1   
Target Milestone: 2.4 M2   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)
Attachments:
Description Flags
log from local AU where all tests passed with the proposed patch none

Description Leonardo Sandoval Gonzalez 2016-06-01 14:56:36 UTC 
We are seeing this output on test_recipetool_appendfile_patch (oeqa.selftest.recipetool.RecipetoolTests)

'Parsing recipes..WARNING: File /etc/selftest-replaceme-patched is added by the patch /home/pokybuild/abc/yocto-autobuilder/yocto-worker/nightly-oe-selftest/build/meta-selftest/recipes-test/recipetool/files/add-file.patch - you may need to remove or replace this patch in order to replace the file.'

Apparently, the string 'Parsing recipes..' is part of output of the n-1 executed command, not the n. A proposed workaround using regex was proposed but the root problem remains.

http://git.yoctoproject.org/cgit/cgit.cgi/poky-contrib/commit/?h=lsandov1/oe-selftest-python3&id=069522737c39bc2c32fdaa3ab96557d37d2e3661
Comment 1 Benjamin Esquivel 2016-06-01 15:00:04 UTC 
Hello Leo, can you provide the steps to reproduce it?
Comment 2 Richard Purdie 2016-06-02 14:44:36 UTC 
I think what is happening is that depending on the previous test, parsing gets triggered and the message then gets corrupted. Under python3 the warning is ending up on the console during parsing, possibly due to changes on when buffers are flushed in different threads/processes.

As Chris Larson suggested on the mailing list, putting errors/warnings to stderr would allow us to better filter them. I'd suggest but bug target trying to improve this issue rather than the current workaround we have.
Comment 3 Leonardo Sandoval Gonzalez 2017-06-14 15:09:47 UTC 
Poky commit 06e9b44f97a4ba5552d2b2ad1d10acd1871ac1ce may have solved this issue. Including Juro, he may have further insight.

commit 06e9b44f97a4ba5552d2b2ad1d10acd1871ac1ce
Refs: yocto-2.3-601-g06e9b44
Author:     Juro Bystricky <juro.bystricky@intel.com>
AuthorDate: Tue Jun 13 09:21:54 2017 -0700
Commit:     Richard Purdie <richard.purdie@linuxfoundation.org>
CommitDate: Wed Jun 14 14:54:24 2017 +0100

    bitbake: bitbake:process: flush stderr/stdout to log

    When a process terminates, some messages may still remain in stdout or
    stderr and do not make it into the log file.
    In addition, the messages that do make it to the log file may end up in
    the log file in incorrect order.
    This patch flushes all messages into the log file after the
    process terminates. Some additional log flushing is also needed
    to keep the various messages showing up in the log file in proper order.

    [YOCTO#10785]
Comment 5 Leonardo Sandoval Gonzalez 2017-06-22 14:42:02 UTC 
Created attachment 3838 [details]
log from local AU where all tests passed with the proposed patch
Comment 6 Leonardo Sandoval Gonzalez 2017-07-07 17:15:17 UTC 
The patch sent was not accepted because it changes a lot the way output strings are parsed. Also, at least Patrick Ohly, working with refkit, needs both outputs (stdout and stderr) in the same variable. In the other hand, the problem has not been observed in the past months and patch from Juro (comment 3) may have fix it. With all the above, resolving as obsolete.