Re: Error logging broken with next?

[Jan Kiszka <jan.kiszka@siemens.com>]

On 24.05.22 18:14, Anton Mikanovich wrote:
> 24.05.2022 19:07, Jan Kiszka wrote:
>> On 24.05.22 18:05, Anton Mikanovich wrote:
>>> 24.05.2022 18:57, Jan Kiszka wrote:
>>>> Just thinking loudly: Is it our try-finally that changes the output
>>>> trigger for knotty?
>>>>
>>>>       try:
>>>>           bb.build.exec_func("dpkg_runbuild", d)
>>>>       finally:
>>>>           bb.build.exec_func("dpkg_undo_mounts", d)
>>>>           bb.utils.unlockfile(lock)
>>>>
>>>> Jan
>>>>
>>> No, this is not because of try-finally itself, but because of exec_func
>>> API.
>>> Look at my previous mail.
>>>
>> But that is just the same with glibc, and that worked fine in poky
>> during my test yesterday, ie. produced the correct dump.
>>
>> Jan
>>
> No, in "glibc" example failed code is executed from the bash task.
> And bb.build.exec_func is python API called from python task.
> This is not the same.
> 
> As I previously said, there is no difference between Yocto and Isar:
> 1) fail in bash task generates full log
> 2) fail in bash code called from python task generates masked log
> 
> Please try do_test example from one of the previous mails on Yocto.
> 

I'm afraid we are talking past each other. This is what I retried again:

$ . oe-init-build-env build

recipe.bb:
LICENSE = ""

test_fun() {
    echo "FAIL!"
    false
}

python do_test() {
    bb.build.exec_func("test_fun", d)
}
addtask test

conf/local.conf:
...

BBFILES += "recipe.bb"


$ bitbake -c test recipe
...
NOTE: No setscene tasks
NOTE: Executing Tasks
ERROR: recipe-1.0-r0 do_test: ExecutionError('/poky-build/tmp/work/core2-64-poky-linux/recipe/1.0-r0/temp/run.test_fun.260', 1, None, None)
ERROR: Logfile of failure stored in: /poky-build/tmp/work/core2-64-poky-linux/recipe/1.0-r0/temp/log.do_test.260
Log data follows:
| DEBUG: Executing python function do_test
| DEBUG: Executing shell function test_fun
| FAIL!
| WARNING: exit code 1 from a shell command.
| DEBUG: Python function do_test finished
ERROR: Task (recipe.bb:do_test) failed with exit code '1'
NOTE: Tasks Summary: Attempted 1 tasks of which 0 didn't need to be rerun and 1 failed.

Summary: 1 task failed:
  recipe.bb:do_test
Summary: There was 1 ERROR message, returning a non-zero exit code.

All fine for me.

Is this what you saw as well?


Now with Isar, using isar-init-build-env instead:
...
NOTE: No setscene tasks
NOTE: Executing Tasks
ERROR: recipe-1.0-r0 do_test: Error executing a python function in exec_python_func() autogenerated:

The stack trace of python calls that resulted in this exception/failure was:
File: 'exec_python_func() autogenerated', lineno: 2, function: <module>
     0001:
 *** 0002:do_test(d)
     0003:
File: 'recipe.bb', lineno: 9, function: do_test
  File "recipe.bb", line 9, in do_test
    bb.build.exec_func("test_fun", d)

File: '/isar/bitbake/lib/bb/build.py', lineno: 256, function: exec_func
     0252:    with bb.utils.fileslocked(lockfiles):
     0253:        if ispython:
     0254:            exec_func_python(func, d, runfile, cwd=adir)
     0255:        else:
 *** 0256:            exec_func_shell(func, d, runfile, cwd=adir)
     0257:
     0258:    try:
     0259:        curcwd = os.getcwd()
     0260:    except:
File: '/isar/bitbake/lib/bb/build.py', lineno: 507, function: exec_func_shell
     0503:    with open(fifopath, 'r+b', buffering=0) as fifo:
     0504:        try:
     0505:            bb.debug(2, "Executing shell function %s" % func)
     0506:            with open(os.devnull, 'r+') as stdin, logfile:
 *** 0507:                bb.process.run(cmd, shell=False, stdin=stdin, log=logfile, extrafiles=[(fifo,readfifo)])
     0508:        except bb.process.ExecutionError as exe:
     0509:            # Find the backtrace that the shell trap generated
     0510:            backtrace_marker_regex = re.compile(r"WARNING: Backtrace \(BB generated script\)")
     0511:            stdout_lines = (exe.stdout or "").split("\n")
File: '/isar/bitbake/lib/bb/process.py', lineno: 186, function: run
     0182:
     0183:    if pipe.returncode != 0:
     0184:        if log:
     0185:            # Don't duplicate the output in the exception if logging it
 *** 0186:            raise ExecutionError(cmd, pipe.returncode, None, None)
     0187:        raise ExecutionError(cmd, pipe.returncode, stdout, stderr)
     0188:    return stdout, stderr
Exception: bb.process.ExecutionError: Execution of '/isar-build/tmp/work/debian-bullseye-armhf/recipe/1.0-r0/temp/run.test_fun.1487' failed with exit code 1

ERROR: Logfile of failure stored in: /isar-build/tmp/work/debian-bullseye-armhf/recipe/1.0-r0/temp/log.do_test.1487
ERROR: Task (recipe.bb:do_test) failed with exit code '1'
NOTE: Tasks Summary: Attempted 1 tasks of which 0 didn't need to be rerun and 1 failed.

Summary: 1 task failed:
  recipe.bb:do_test
Summary: There was 1 ERROR message shown, returning a non-zero exit code.


This is NOT what we want to have. And this is an Isar bug at this level.

Jan

-- 
Siemens AG, Technology
Competence Center Embedded Linux