Bug 7802

Summary: Insufficient info provided when a recipe fails.
Product: [Build System, Metadata & Runtime] BitBake Reporter: Igor Stoppa <igor.stoppa>
Component: bitbakeAssignee: Richard Purdie <richard.purdie>
Status: RESOLVED FIXED QA Contact:
Severity: enhancement    
Priority: Medium CC: barbieri, dmitry.rojkov, poky.bs.watcher, poky.watcher, randy.macleod
Version: unspecified   
Target Milestone: Future   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: Don't know

Description Igor Stoppa 2015-05-21 18:28:34 UTC
When a recipe fails, the output points only to a temporary build file that experienced the error.
It shows the line that caused the error.

This is not very nice to debug because: 

1) the temporary script is based on a recipe, after parameters have been replaced, so it's not possible to do a simple grep against the recipe

2) no line number for the error is shown, it would facilitate the debugging
in cases where the recipe has lots of similar lines (pre replacement of the parameters)

It might just work if one is the author of the recipe, but for those who need to work with someone else's recipe, this is really frustrating.
Comment 1 Richard Purdie 2015-05-28 14:40:46 UTC
The problem here is that it is not easy to map the line numbers in the shell scripts back to which variables make up that line and the multiple lines in multiple files which may have contributed to it.

As such we'd need some kind of plan as to how we'd store this data (without degrading performance) and also how to display it in a way which the user could understand. This is why its being marked as future since we don't have a good plan.

If you have specific suggestions about how we could improve things please make them and we can rethink the target/priority.

Also, putting an example of a failure which we could reproduce and use as a case study would be useful to help others understand this issue.
Comment 2 Igor Stoppa 2015-05-28 14:53:40 UTC
With my limited knowledge of the guts of Yocto, the way I would do it, is to build also a separate file with all the extra info.

Ex: lines number and names of the recipes/whatever where the code originates from.

The only important part is that the 2 files map 1:1 in terms of line number.

Then just show both files: the one executed and the "helper".

This will show both the version w/ and w/o substitution.

I don't think you would get a big overhead just from this.

To reproduce the problem, simply modify a .bb file so that it is buggy and fails.

Which is the typical scenario one gets when debugging a system with several recipes and layers.
Comment 3 Igor Stoppa 2015-06-01 07:04:40 UTC
Btw, the line number could be provided at least when a .bb file fails, but even there it's not provided. This shouldn't be affected by al lthe impediments described above.
Comment 4 Richard Purdie 2015-06-02 21:24:17 UTC
(In reply to comment #2)
> With my limited knowledge of the guts of Yocto, the way I would do it, is to
> build also a separate file with all the extra info.
> 
> Ex: lines number and names of the recipes/whatever where the code originates
> from.
> 
> The only important part is that the 2 files map 1:1 in terms of line number.

There is no such mapping though since a variable may expand into multiple lines. Functions are just variables as far as bitbake is concerned. Consider:

a.bbclass:

do_compile () {






> Then just show both files: the one executed and the "helper".
> 
> This will show both the version w/ and w/o substitution.
> 
> I don't think you would get a big overhead just from this.
> 
> To reproduce the problem, simply modify a .bb file so that it is buggy and
> fails.
> 
> Which is the typical scenario one gets when debugging a system with several
> recipes and layers.
Comment 5 Richard Purdie 2015-06-02 21:30:06 UTC
(In reply to comment #2)
> With my limited knowledge of the guts of Yocto, the way I would do it, is to
> build also a separate file with all the extra info.
> 
> Ex: lines number and names of the recipes/whatever where the code originates
> from.
> 
> The only important part is that the 2 files map 1:1 in terms of line number.

There is no such mapping though since a variable may expand into multiple lines. Functions are just variables as far as bitbake is concerned. Consider:

a.bbclass:

SOMEPARAM = "a"

do_compile () {
    <command1> ${SOMEPARAM}
    <command2>
}

b.bbclass:

SOMEPARAM_append = "b"
do_compile_append = "; <command3>"

So for both the function and the variables you have multiple files contributing to a single line in the output.

Have you looked at bitbake <recipe> -e? That attempts to show the variable history for any variable at least.

> Then just show both files: the one executed and the "helper".
> 
> This will show both the version w/ and w/o substitution.
> 
> I don't think you would get a big overhead just from this.

We actually have measurements of the overhead that variable history tracking has and it is significant. We don't enable it by default, just for commands like bitbake -e.

> To reproduce the problem, simply modify a .bb file so that it is buggy and
> fails.

When it fails, just simply find the problem and fix it then. 

You might find the answer above unhelpful and perhaps slightly annoying. My answer is being about as specific as you're being here. If you'd like me to be helpful, at least put some effort into reporting this so for example we have a common test case we're looking at. There are 101 ways you can cause bitbake to fail, I'd like to ensure we're talking about the same scenario.
Comment 6 Richard Purdie 2015-06-02 21:31:02 UTC
(In reply to comment #3)
> Btw, the line number could be provided at least when a .bb file fails, but
> even there it's not provided. This shouldn't be affected by al lthe
> impediments described above.

As I've tried to explain, there is no such magic mapping. The line may come from a class file, or a .inc file or in fact may be constructed from several different files.
Comment 7 Igor Stoppa 2015-06-02 21:43:28 UTC
(In reply to comment #5)

> There is no such mapping though since a variable may expand into multiple
> lines. Functions are just variables as far as bitbake is concerned.

ok, now I understand. These are in practice more like C macros than functions.
I was mislead by the fact that they look like bash / python functions.

> Have you looked at bitbake <recipe> -e? That attempts to show the variable
> history for any variable at least.

Thanks, I will try it.

> > To reproduce the problem, simply modify a .bb file so that it is buggy and
> > fails.
> 
> When it fails, just simply find the problem and fix it then. 
> 
> You might find the answer above unhelpful and perhaps slightly annoying. 

You have to do better than that ;-)

(But please do not take it as a challenge :-P )

> My
> answer is being about as specific as you're being here. If you'd like me to
> be helpful, at least put some effort into reporting this so for example we
> have a common test case we're looking at. There are 101 ways you can cause
> bitbake to fail, I'd like to ensure we're talking about the same scenario.

It's not the effort that I dislike, it is the fact that I don't want to report an example that might be dismissed with an ad-hoc workaround.

In practice the only commonality I could find between all the cases I experienced is that some script was failing to execute, in a way that would cause an error (and I suspect it just meant retval not 0).

From what I recall, examples are: trying to copy a file that doesn't exist, trying to create a directory in a path that doesn't exist, etc. Almost anything that would generate some shell command to fail.
Comment 8 Gustavo Sverzut Barbieri 2015-11-26 19:27:25 UTC
Hi Richard and Igor,

Taking a look at this issue, that is open for 6 months :-(, I can try to help both parts to come to an agreement.

First, Igor's point is also a pain for other users. Myself included when tasked to generate images that includes couple of ".bb" for the same recipe (which one was used?), each based on ".bbclass", and likely with some multiple ".bbappend" (like specific an generic versions).

However, I understand Richard's concerns regarding difficult of implementations, particularly the concerns with performance.

My approach to implement a solution is to act post-error, not try to overload the general process when it works, but once it fails, then at least parts of the following should be doable:

 -> re-execute the steps in extra verbose mode, this would allow you to print all the resolution that lead to variables being their current value, commands being executed and so on. So you'd print, in your example:

   $PATHTO/a.bbclass:123:SOMEPARAM="a"
   $PATHTO/a.bbclass:456:do_compile():
      do_compile () {
          <command1> ${SOMEPARAM}
          <command2>
      }
   $PATHTO/b.bbclass:78:do_compile (append): "; <command3>":
      do_compile () {
          <command1> ${SOMEPARAM}
          <command2>
          <command3>
      }
   $PATHTO/b.bbclass:90:SOMEPATH (append): "b"
   $PATHTO/b.bbclass:90:SOMEPATH="ab"

   Then, during execution print in a similar way to set -x:
   $PATHTO/a.bbclass:457:do_compile (exec[0]): <command1> ${SOMEPARAM}
   $PATHTO/a.bbclass:457:do_compile (exec[0]): <command1> "ab"
   $PATHTO/a.bbclass:458:do_compile (exec[1]): <command2>
   $PATHTO/a.bbclass:458:do_compile (exec[1]): <command2>
   $PATHTO/c.bbclass:78:do_compile (exec[2]): <command3>
   $PATHTO/b.bbclass:78:do_compile (exec[2]): ERROR: file not found <command2>
   $PATHTO/c.bb:13: Traceback: called from here: inherit b


Eventually this is too verbose, but you get the idea. Right now it's almost impossible to see what's going on if you don't have experience with the failing recipe, like if you're doing a distro build after an update.
Comment 9 Richard Purdie 2021-08-04 13:56:16 UTC
We added comments to code fragment and these are used to help provide more useful tracebacks. Example code looks like:

# line: 54, file: /media/build2/poky-override/meta/classes/logging.bbclass
bbfatal() {
        [...]
	exit 1
}

# line: 66, file: /media/build2/poky-override/meta/classes/logging.bbclass
bbfatal_log() {
        [...]	exit 1
}

and I think this is close as we're going to be able to  get for this bug.