Bug 10993

Summary: eSDK installation log file is incomplete in case of failure
Product: [Yocto Project Subprojects] eSDK Reporter: Geoffroy Van Cutsem <geoffroy.vancutsem>
Component: eSDKAssignee: Stanley Phoong <stanley.cheong.kwan.phoong>
Status: RESOLVED WORKSFORME QA Contact: Francisco Pedraza <francisco.j.pedraza.gonzalez>
Severity: normal    
Priority: Medium+ CC: bluelightning, rebecca.swee.fun.chang, stanley.cheong.kwan.phoong
Version: unspecified   
Target Milestone: 2.3 M4   
Hardware: x86   
OS: Multiple   
Whiteboard:
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Geoffroy Van Cutsem 2017-01-31 14:18:30 UTC
In case of a failed installation of the eSDK, the message points at the "preparing_build_system.log" log file for more information. However, this file only contains partial information about the failure and more specifically, it does not contain any of the errors that led to the failure. See below for the full content of the log file [1] and a cut version of the output I got on the terminal [2].

[1] Full content of "preparing_build_system.log":
### Shell environment set up for builds. ###

You can now run 'bitbake <target>'

Common targets are:
    core-image-minimal
    core-image-sato
    meta-toolchain
    meta-ide-support

You can also run generated qemu images with a command like 'runqemu qemux86'
Preparing SDK for meta-world-pkgdata:do_allpackagedata...

[2] Output on the terminal:
Ostro OS Extensible SDK installer version 1.0+snapshot ======================================================
You are about to install the SDK to "/home/gvancuts/tmp". Proceed[Y/n]?
Extracting SDK......done
Setting it up...
Extracting buildtools...
Preparing build system...
Parsing recipes: 100% |#############################################################################################| Time: 0:02:24 Initialising tasks: 100% |##########################################################################################| Time: 0:00:05
ERROR: Sstate artifact unavailable for libarchive.do_populate_sysroot                                               | ETA:  0:00:00
ERROR: Sstate artifact unavailable for initscripts.do_package                                                       | ETA:  0:00:00
ERROR: Sstate artifact unavailable for swupd-client.do_package                                                      | ETA:  0:00:00
ERROR: Sstate artifact unavailable for hello-bundle-s.do_package                                                    | ETA:  0:00:00
ERROR: Sstate artifact unavailable for shadow.do_package                                                            | ETA:  0:00:00
ERROR: Sstate artifact unavailable for glibc-mtrace.do_package                                                      | ETA:  0:00:00
ERROR: Sstate artifact unavailable for v86d.do_package                                                              | ETA:  0:00:00
ERROR: Sstate artifact unavailable for libcgroup.do_package                                                         | ETA:  0:00:00
ERROR: Sstate artifact unavailable for python-setuptools.do_package                                                 | ETA:  0:00:00
ERROR: Sstate artifact unavailable for automake.do_package                                                          | ETA:  0:00:00
ERROR: Sstate artifact unavailable for libffi.do_package                                                            | ETA:  0:00:00
ERROR: Sstate artifact unavailable for libjpeg-turbo.do_populate_sysroot                                            | ETA:  0:00:00
ERROR: Sstate artifact unavailable for unzip-native.do_populate_sysroot                                             | ETA:  0:00:00
ERROR: Sstate artifact unavailable for commons-net-native.do_populate_sysroot                                       | ETA:  0:00:00
ERROR: Sstate artifact unavailable for icu.do_package                                                               | ETA:  0:00:00
ERROR: Sstate artifact unavailable for libpng.do_populate_sysroot                                                   | ETA:  0:00:00
<snip>
Comment 1 Rebecca Chang 2017-03-30 02:02:44 UTC
Hi Geoffroy, could you share the steps to reproduce? I'm new in eSDK but I would like to help out in debugging and solving this issue. By the way, I'm using Ubuntu 16.04 host. Is there any constraint on reproducing the bug? Are you run on a docker environment?
Comment 2 Paul Eggleton 2017-03-30 11:44:41 UTC
I suspect Geoffroy may not be able to reproduce this error, but it should be fairly easy to force a failure if you deliberately break meta/files/ext-sdk-prepare.py.
Comment 3 Geoffroy Van Cutsem 2017-03-31 09:53:34 UTC
I hit this as part of a somewhat complex debugging session and I don't recall exactly what my environment was set-up to. I can go back to my notes in case you can't easily reproduce this but we'll likely end up with a somewhat complex set-up.
Comment 4 Stanley Phoong 2017-04-03 02:33:15 UTC
Hi, we are trying to reproduce this error. But we can't get the same error. 

We're using poky/Yocto, and we realized that you're using Ostro OS from "https://github.com/ostroproject/ostro-os".

We couldn't find "bb.error('Sstate artifact unavailable for %s.%s' % (pn, taskname))" inside sstate.bbclass from Yocto Project but we could find this error string inside Ostro OS.

This error string has been removed from Yocto Project in this commit https://patchwork.openembedded.org/patch/136050/

Are we on the right track?

Also, we're still new in eSDK and we're not sure where to find the error logs to print onto the meta/files/ext-sdk-prepare.py. Do you have any tips on this for us? Thank you.
Comment 5 Rebecca Chang 2017-04-03 09:08:41 UTC
If we are understanding this issue properly, you're saying that the messages from the terminal is not printed into the "preparing_build_system.log".

We have tried to reproduce the issue by trying to deliberately break the installation of eSDK. However the "preparing_build_system.log" file shows the same output as the terminal.

You can refer to the logs that we captured here:
Terminal log (stderr):
https://drive.google.com/open?id=0B0WsVqYXcnl1eHRqRTR3dmtwS1U

preparing_build_system.log file:
https://drive.google.com/open?id=0B0WsVqYXcnl1NXFpNGpwY2RNcFU

As you can see the logs are similar and it does print out in "preparing_build_system.log".

We suspect that you are using an older version of Poky and you are basing off Ostro project. You might want to update your bitbake source revision in your combo-layer.conf.
Comment 6 Geoffroy Van Cutsem 2017-04-03 11:10:45 UTC
This is correct, all work was based off the Ostro Project. Based on Paul's commit that removed some code in sstate.class, I don't think it's even possible to trigger the same error. The only test that would get us a little closer to where we were is if there is a code path that would trigger a bb.fatal somewhere from sstate.class and see if in that case, all error messages are correctly put in the log file... but I have no idea how to do that so I'm fine closing this issue on my side. Thanks, Geoffroy
Comment 7 Stanley Phoong 2017-04-04 03:30:48 UTC
Unable to reproduce the bug. If this issue re-appears in the future again, we can re-open this bug.
Comment 8 Paul Eggleton 2017-04-04 04:35:13 UTC
Adjusting to WORKSFORME since that's more applicable in this case.