Bug 10046

Summary: Progress bar sometimes leaves old bars on screen
Product: [Build System, Metadata & Runtime] BitBake Reporter: Yi Zhao <yi.zhao>
Component: bitbakeAssignee: Paul Eggleton <bluelightning>
Status: RESOLVED FIXED QA Contact: Yi Zhao <yi.zhao>
Severity: normal    
Priority: Medium+ CC: jose.perez.carranza, juro.bystricky, net147, poky.bs.watcher, poky.watcher, richard.purdie, ross.burton, sgw, yi.zhao
Version: 2.2   
Target Milestone: 2.2 M4   
Hardware: All   
OS: Multiple   
Whiteboard: YP 2.2 M4 RC1 BUILD BLOCKING BUG
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)
Attachments:
Description Flags
Bad example none

Description Yi Zhao 2016-07-28 07:21:28 UTC
Git rev: master/36feb38045b7a2af86ece147fec54b0db3bf491f

When building image, the process bar of running tasks (not the parsing process bar) has some strange behavior. It overlaps sometimes and doesn't show 100% when build complete.

$ bitbake core-image-minimal
Parsing recipes: 100% |################################################################################################################################| Time: 0:00:23
Parsing of 865 .bb files complete (0 cached, 865 parsed). 1313 targets, 49 skipped, 0 masked, 0 errors.
NOTE: Resolving any missing task queue dependencies

Build Configuration:
BB_VERSION        = "1.31.0"
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "Ubuntu-16.04"
TARGET_SYS        = "i586-poky-linux"
MACHINE           = "qemux86"
DISTRO            = "poky"
DISTRO_VERSION    = "2.1+snapshot-20160727"
TUNE_FEATURES     = "m32 i586"
TARGET_FPU        = ""
meta              
meta-poky         
meta-yocto-bsp    = "master:36feb38045b7a2af86ece147fec54b0db3bf491f"

Initialising tasks: 100% |#############################################################################################################################| Time: 0:00:04
NOTE: Executing SetScene Tasks
NOTE: Executing RunQueue Tasks
Currently  7 running tasks (1785 of 2020)  88% |#######################################################################################################              |
0: perl-5.22.1-r0 do_compile (pid 12094)
Currently  5 running tasks (1944 of 2020)  96% |################################################################################################################     |
No currently running tasks (1975 of 2020)  97% |##################################################################################################################   |
NOTE: Tasks Summary: Attempted 2020 tasks of which 9 didn't need to be rerun and all succeeded.
Comment 1 Ross Burton 2016-07-28 15:26:42 UTC
I think the real bug here is that occasionally the progress bar gets left on screen, presumably from an off-by-one in the line width calculation or something similar.  The bars you can see are not the in progress ones so I suspect the actual bar does get to 100% if you watch it live.
Comment 2 Yi Zhao 2016-07-29 09:38:19 UTC
(In reply to comment #1)
> I think the real bug here is that occasionally the progress bar gets left on
> screen, presumably from an off-by-one in the line width calculation or
> something similar.  The bars you can see are not the in progress ones so I
> suspect the actual bar does get to 100% if you watch it live.

Yes, you are right.

Here is a regular processes bar with few tasks (I rebuild it). There is no task progress bar gets left on screen.
 
$ bitbake core-image-sato-sdk
Loading cache: 100% |##################################################################################################################################| Time: 0:00:00
Loaded 1312 entries from dependency cache.
NOTE: Resolving any missing task queue dependencies

Build Configuration:
BB_VERSION        = "1.31.0"
BUILD_SYS         = "x86_64-linux"
NATIVELSBSTRING   = "universal"
TARGET_SYS        = "arm-poky-linux-gnueabi"
MACHINE           = "qemuarm"
DISTRO            = "poky"
DISTRO_VERSION    = "2.1+snapshot-20160729"
TUNE_FEATURES     = "arm armv5 thumb dsp"
TARGET_FPU        = "soft"
meta              
meta-poky         
meta-yocto-bsp    = "master:039f47ad197a9a53109c9f3deadd9c35e62c056d"

Initialising tasks: 100% |#############################################################################################################################| Time: 0:00:10
NOTE: Executing SetScene Tasks
NOTE: Executing RunQueue Tasks
NOTE: Tasks Summary: Attempted 6338 tasks of which 6328 didn't need to be rerun and all succeeded.
Comment 3 Ross Burton 2016-08-15 10:56:25 UTC
Created attachment 3356 [details]
Bad example

This just happened to me. There must be an off-by-one somewhere that makes it think that a line will fit the terminal when it won't.
Comment 4 Paul Eggleton 2016-09-14 23:54:50 UTC
Is there any known procedure I can use in order to reproduce this?
Comment 5 Ross Burton 2016-09-15 11:51:48 UTC
This happens periodically for me, and I can't see any reason for it sorry.
Comment 6 Jonathan Liu 2016-09-27 05:52:43 UTC
For me this happens as a result of https://bugzilla.yoctoproject.org/show_bug.cgi?id=10024. The "Child process exit status 4: lock_held" message is printed for a short moment and gets overridden when this happens.
Comment 7 Ross Burton 2016-09-27 12:55:28 UTC
Sorry Paul but your potential fix doesn't help me.  With current master:

...
Initialising tasks: 100% |##############################################################################################| Time: 0:00:23
NOTE: Executing SetScene Tasks
NOTE: Executing RunQueue Tasks
Currently 10 running tasks (5802 of 6892)  84% |########################################################################              |
Currently 10 running tasks (5804 of 6892)  84% |########################################################################              |
Currently  8 running tasks (6235 of 6892)  90% |#############################################################################         |
0: glib-2.0-1_2.48.2-r0 do_package - 13s (pid 17161)
...

The pseudo theory is a candidate, I wasn't watching this build so wouldn't have noticed the lock_held messages.
Comment 8 Juro Bystricky 2016-09-29 22:45:42 UTC
Also observed when "Child process exit status 4: lock_held" message is printed.
These messages can show up in bunches of "n" lines and the process bar is then also offset by "n" lines.
Comment 9 Paul Eggleton 2016-10-03 17:04:52 UTC
Since the following commit went in, are you guys still observing this issue?

http://cgit.openembedded.org/openembedded-core/commit/?id=efd0b0f604f9f498b9c20bc9a25708c493aa4f4a
Comment 10 Juro Bystricky 2016-10-03 17:08:01 UTC
Haven't seen any abnormal KnottyUI output (process bar) lately.
with master:3a73fe0efcb7aeefcca7011bba887caad03d4d03
Comment 11 Ross Burton 2016-10-03 18:41:20 UTC
Same here.  Let's close this and see if anyone can replicate to reopen.
Comment 12 Richard Purdie 2016-10-04 09:43:28 UTC
We believe the pseudo logging fix has fixed the output that was going to stdin and causing bitbake UI corruption. If we still see the issue we can reopen or file a new specific bug for the issue but believe this is resolved.