[Buildroot] [PATCH 0/2] Support for generating a timeline graph

[Buildroot] [PATCH 0/2] Support for generating a timeline graph

[Thomas Petazzoni]

Hello,

As part of the work on top-level parallel build, I found that it would
be interesting to be able to draw a timeline of the build, to see how
packages are being built in parallel or not. Not only it generates
nice graphs that are interesting to look at, but it also allows to
visually see which package was built in parallel to what other
packages, or before/after this or that other packages.

You can see one timeline graph for a non-parallel build at:

  https://bootlin.com/~thomas/timeline-no-parallel.png
  https://bootlin.com/~thomas/timeline-no-parallel.pdf

And you can see the timeline graph for the same build, with with
parallel build enabled at:

  https://bootlin.com/~thomas/timeline-parallel.png
  https://bootlin.com/~thomas/timeline-parallel.pdf

This patch series is pretty simple:

 - The first patch adds sub-second precision to the timestamps we keep
   in build-time.log.

 - The second patch adds support in the graph-build-time script to
   generate such a timeline. The whole thing is not perfect yet (the
   layout of the graph could be improved, some hardcoded values could
   be removed), but it's a good start, and follow-up patches can
   improve the graph layout.

To test this, just do a build, run "make graph-build", and enjoy the
graph in output/graphs/build.timeline.pdf.

Thanks,

Thomas

Thomas Petazzoni (2):
  package/pkg-generic.mk: increase precision of timestamps
  support/scripts/graph-build-time: add support for timeline graphing

 Makefile                         |  2 ++
 package/pkg-generic.mk           |  2 +-
 support/scripts/graph-build-time | 73 ++++++++++++++++++++++++++++++++++++++--
 3 files changed, 74 insertions(+), 3 deletions(-)

-- 
2.14.4

[Buildroot] [PATCH 1/2] package/pkg-generic.mk: increase precision of timestamps

[Thomas Petazzoni]

Currently, the timestamps that we keep in build-time.log use a
second-level precision. However, as we are going to introduce a new
type of graph to draw the time line of a build, this precision is
going to be insufficient, as a number of steps are so short that they
are not even one second long, and generally the rounding to the second
gives a not so great looking graph.

Therefore, we add to the timestamps the nanoseconds using the %N date
specifier. A milli-second precision would have been sufficient, but %N
is all what date(1) provides at the sub-second level.

Since this is changing the format of the build-time.log file, this
commit adjusts the support/scripts/graph-build-time script
accordingly, to account for the floating point numbers that we have as
timestamps.

Signed-off-by: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
---
 package/pkg-generic.mk           | 2 +-
 support/scripts/graph-build-time | 2 +-
 2 files changed, 2 insertions(+), 2 deletions(-)

diff --git a/package/pkg-generic.mk b/package/pkg-generic.mk
index 91b61c6de0..daf24594de 100644
--- a/package/pkg-generic.mk
+++ b/package/pkg-generic.mk
@@ -50,7 +50,7 @@ endef
 # Time steps
 define step_time
 	printf "%s:%-5.5s:%-20.20s: %s\n"           \
-	       "$$(date +%s)" "$(1)" "$(2)" "$(3)"  \
+	       "$$(date +%s.%N)" "$(1)" "$(2)" "$(3)"  \
 	       >>"$(BUILD_DIR)/build-time.log"
 endef
 GLOBAL_INSTRUMENTATION_HOOKS += step_time
diff --git a/support/scripts/graph-build-time b/support/scripts/graph-build-time
index 415d431f23..892e08bf07 100755
--- a/support/scripts/graph-build-time
+++ b/support/scripts/graph-build-time
@@ -260,7 +260,7 @@ def read_data(input_file):
         return None
 
     for row in reader:
-        time = int(row[0].strip())
+        time = float(row[0].strip())
         state = row[1].strip()
         step = row[2].strip()
         pkg = row[3].strip()
-- 
2.14.4

[Buildroot] [PATCH 1/2] package/pkg-generic.mk: increase precision of timestamps

[Yann E. MORIN]

Thomas, All,

On 2018-09-21 15:31 +0200, Thomas Petazzoni spake thusly:
> Currently, the timestamps that we keep in build-time.log use a
> second-level precision. However, as we are going to introduce a new
> type of graph to draw the time line of a build, this precision is
> going to be insufficient, as a number of steps are so short that they
> are not even one second long, and generally the rounding to the second
> gives a not so great looking graph.
> 
> Therefore, we add to the timestamps the nanoseconds using the %N date
> specifier. A milli-second precision would have been sufficient, but %N
> is all what date(1) provides at the sub-second level.

%N has existed since at least 2002, when it was actually documented in
commit 17e6a0e4bb. So, we can conclude that %N is universally availble.

Besides, %N can provide millisecond precision, by specifying the
precision, like so:

    date +%3N

But I still think plain %N is OK as well, and I don't know since when
that has been possible, so:

Acked-by: "Yann E. MORIN" <yann.morin.1998@free.fr>

Regards,
Yann E. MORIN.

> Since this is changing the format of the build-time.log file, this
> commit adjusts the support/scripts/graph-build-time script
> accordingly, to account for the floating point numbers that we have as
> timestamps.
> 
> Signed-off-by: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
> ---
>  package/pkg-generic.mk           | 2 +-
>  support/scripts/graph-build-time | 2 +-
>  2 files changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/package/pkg-generic.mk b/package/pkg-generic.mk
> index 91b61c6de0..daf24594de 100644
> --- a/package/pkg-generic.mk
> +++ b/package/pkg-generic.mk
> @@ -50,7 +50,7 @@ endef
>  # Time steps
>  define step_time
>  	printf "%s:%-5.5s:%-20.20s: %s\n"           \
> -	       "$$(date +%s)" "$(1)" "$(2)" "$(3)"  \
> +	       "$$(date +%s.%N)" "$(1)" "$(2)" "$(3)"  \
>  	       >>"$(BUILD_DIR)/build-time.log"
>  endef
>  GLOBAL_INSTRUMENTATION_HOOKS += step_time
> diff --git a/support/scripts/graph-build-time b/support/scripts/graph-build-time
> index 415d431f23..892e08bf07 100755
> --- a/support/scripts/graph-build-time
> +++ b/support/scripts/graph-build-time
> @@ -260,7 +260,7 @@ def read_data(input_file):
>          return None
>  
>      for row in reader:
> -        time = int(row[0].strip())
> +        time = float(row[0].strip())
>          state = row[1].strip()
>          step = row[2].strip()
>          pkg = row[3].strip()
> -- 
> 2.14.4
> 

-- 
.-----------------.--------------------.------------------.--------------------.
|  Yann E. MORIN  | Real-Time Embedded | /"\ ASCII RIBBON | Erics' conspiracy: |
| +33 662 376 056 | Software  Designer | \ / CAMPAIGN     |  ___               |
| +33 223 225 172 `------------.-------:  X  AGAINST      |  \e/  There is no  |
| http://ymorin.is-a-geek.org/ | _/*\_ | / \ HTML MAIL    |   v   conspiracy.  |
'------------------------------^-------^------------------^--------------------'

[Buildroot] [PATCH 1/2] package/pkg-generic.mk: increase precision of timestamps

[Thomas Petazzoni]

Hello,

On Fri, 21 Sep 2018 15:31:16 +0200, Thomas Petazzoni wrote:
> Currently, the timestamps that we keep in build-time.log use a
> second-level precision. However, as we are going to introduce a new
> type of graph to draw the time line of a build, this precision is
> going to be insufficient, as a number of steps are so short that they
> are not even one second long, and generally the rounding to the second
> gives a not so great looking graph.
> 
> Therefore, we add to the timestamps the nanoseconds using the %N date
> specifier. A milli-second precision would have been sufficient, but %N
> is all what date(1) provides at the sub-second level.
> 
> Since this is changing the format of the build-time.log file, this
> commit adjusts the support/scripts/graph-build-time script
> accordingly, to account for the floating point numbers that we have as
> timestamps.
> 
> Signed-off-by: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
> ---
>  package/pkg-generic.mk           | 2 +-
>  support/scripts/graph-build-time | 2 +-
>  2 files changed, 2 insertions(+), 2 deletions(-)

Applied to master, thanks.

Thomas
-- 
Thomas Petazzoni, CTO, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com

[Buildroot] [PATCH 2/2] support/scripts/graph-build-time: add support for timeline graphing

[Thomas Petazzoni]

This commit adds support for a new type of graph, showing the timeline
of a build. It shows, with one line per package, when each of this
package steps started/ended, and therefore allows to see the
sequencing of the package builds.

For a fully serialized build like we have today, this is not super
useful (except to show that everything is serialized), but it becomes
much more useful in the context of top-level parallel build.

The graph-build make target is extended to also generate this new
timeline graph.

Signed-off-by: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
---
 Makefile                         |  2 ++
 support/scripts/graph-build-time | 71 +++++++++++++++++++++++++++++++++++++++-
 2 files changed, 72 insertions(+), 1 deletion(-)

diff --git a/Makefile b/Makefile
index 18afa36b28..49f1106213 100644
--- a/Makefile
+++ b/Makefile
@@ -831,6 +831,8 @@ graph-build: $(O)/build/build-time.log
 				   --type=pie-$(t) --input=$(<) \
 				   --output=$(GRAPHS_DIR)/build.pie-$(t).$(BR_GRAPH_OUT) \
 				   $(if $(BR2_GRAPH_ALT),--alternate-colors)$(sep))
+	./support/scripts/graph-build-time --type=timeline --input=$(<) \
+		--output=$(GRAPHS_DIR)/build.timeline.$(BR_GRAPH_OUT)
 
 .PHONY: graph-depends-requirements
 graph-depends-requirements:
diff --git a/support/scripts/graph-build-time b/support/scripts/graph-build-time
index 892e08bf07..c4aa066050 100755
--- a/support/scripts/graph-build-time
+++ b/support/scripts/graph-build-time
@@ -240,6 +240,73 @@ def pkg_pie_time_per_step(data, output):
     plt.title('Build time per step')
     plt.savefig(output)
 
+step_colors = {
+    'download': 'blue',
+    'extract': 'red',
+    'patch': 'green',
+    'configure': 'black',
+    'build': 'cyan',
+    'install-target': 'orange',
+    'install-staging': 'yellow',
+    'install-images': 'purple',
+    'install-host': 'grey'
+}
+
+def pkg_timeline(data, output):
+    start = 0
+    end = 0
+
+    # Find the first timestamp and the last timestamp
+    for p in data:
+        for k, v in p.steps_start.iteritems():
+            if start == 0 or v < start:
+                start = v
+            if end < v:
+                end = v
+
+    # Readjust all timestamps so that 0 is the start of the build
+    # instead of being Epoch
+    for p in data:
+        for k, v in p.steps_start.iteritems():
+            p.steps_start[k] = v - start
+        for k, v in p.steps_end.iteritems():
+            p.steps_end[k] = v - start
+
+    plt.figure()
+
+    i = 0
+    labels_names = []
+    labels_coords = []
+    # reversing the list, because the packages build first appear last in the list
+    for p in reversed(data):
+        durations = []
+        colors = []
+        for step in steps:
+            if not step in p.steps_start or not step in p.steps_end:
+                continue
+            durations.append((p.steps_start[step],
+                              p.steps_end[step] - p.steps_start[step]))
+            colors.append(step_colors[step])
+        plt.broken_barh(durations, (i, 6), facecolors=colors)
+        labels_coords.append(i + 3)
+        labels_names.append(p.name)
+        i += 10
+
+    axes = plt.gcf().gca()
+
+    axes.set_ylim(0, i + 10)
+    axes.set_xlim(0, end - start)
+    axes.set_xlabel('seconds since start')
+    axes.set_yticks(labels_coords)
+    axes.set_yticklabels(labels_names)
+    axes.set_axisbelow(True)
+    axes.grid(True, linewidth=0.2, zorder=-1)
+
+    plt.gcf().subplots_adjust(left=0.2)
+
+    plt.tick_params(axis='y', which='both', labelsize=6)
+    plt.title('Timeline')
+    plt.savefig(output, dpi=300)
 
 # Parses the csv file passed on standard input and returns a list of
 # Package objects, filed with the duration of each step and the total
@@ -277,7 +344,7 @@ def read_data(input_file):
 
 parser = argparse.ArgumentParser(description='Draw build time graphs')
 parser.add_argument("--type", '-t', metavar="GRAPH_TYPE",
-                    help="Type of graph (histogram, pie-packages, pie-steps)")
+                    help="Type of graph (histogram, pie-packages, pie-steps, timeline)")
 parser.add_argument("--order", '-O', metavar="GRAPH_ORDER",
                     help="Ordering of packages: build or duration (for histogram only)")
 parser.add_argument("--alternate-colors", '-c', action="store_true",
@@ -307,6 +374,8 @@ elif args.type == "pie-packages":
     pkg_pie_time_per_package(d, args.output)
 elif args.type == "pie-steps":
     pkg_pie_time_per_step(d, args.output)
+elif args.type == "timeline":
+    pkg_timeline(d, args.output)
 else:
     sys.stderr.write("Unknown type: %s\n" % args.type)
     exit(1)
-- 
2.14.4

[Buildroot] [PATCH 2/2] support/scripts/graph-build-time: add support for timeline graphing

[Matthew Weber]

Thomas,

On Fri, Sep 21, 2018 at 8:31 AM Thomas Petazzoni
<thomas.petazzoni@bootlin.com> wrote:
>
> This commit adds support for a new type of graph, showing the timeline
> of a build. It shows, with one line per package, when each of this
> package steps started/ended, and therefore allows to see the
> sequencing of the package builds.
>
> For a fully serialized build like we have today, this is not super
> useful (except to show that everything is serialized), but it becomes
> much more useful in the context of top-level parallel build.
>
> The graph-build make target is extended to also generate this new
> timeline graph.

Is there a way to remove the page boundary or split the data so larger
builds are readable?  I'm not sure of the readablility point but my
build test of ~80-100pkg target was overlapping.

>
> Signed-off-by: Thomas Petazzoni <thomas.petazzoni@bootlin.com>
> ---
>  Makefile                         |  2 ++
>  support/scripts/graph-build-time | 71 +++++++++++++++++++++++++++++++++++++++-
>  2 files changed, 72 insertions(+), 1 deletion(-)
>
> diff --git a/Makefile b/Makefile
> index 18afa36b28..49f1106213 100644
> --- a/Makefile
> +++ b/Makefile
> @@ -831,6 +831,8 @@ graph-build: $(O)/build/build-time.log
>                                    --type=pie-$(t) --input=$(<) \
>                                    --output=$(GRAPHS_DIR)/build.pie-$(t).$(BR_GRAPH_OUT) \
>                                    $(if $(BR2_GRAPH_ALT),--alternate-colors)$(sep))
> +       ./support/scripts/graph-build-time --type=timeline --input=$(<) \
> +               --output=$(GRAPHS_DIR)/build.timeline.$(BR_GRAPH_OUT)
>
>  .PHONY: graph-depends-requirements
>  graph-depends-requirements:
> diff --git a/support/scripts/graph-build-time b/support/scripts/graph-build-time
> index 892e08bf07..c4aa066050 100755
> --- a/support/scripts/graph-build-time
> +++ b/support/scripts/graph-build-time
> @@ -240,6 +240,73 @@ def pkg_pie_time_per_step(data, output):
>      plt.title('Build time per step')
>      plt.savefig(output)
>
> +step_colors = {
> +    'download': 'blue',
> +    'extract': 'red',
> +    'patch': 'green',
> +    'configure': 'black',
> +    'build': 'cyan',
> +    'install-target': 'orange',
> +    'install-staging': 'yellow',
> +    'install-images': 'purple',
> +    'install-host': 'grey'
> +}
> +
> +def pkg_timeline(data, output):
> +    start = 0
> +    end = 0
> +
> +    # Find the first timestamp and the last timestamp
> +    for p in data:
> +        for k, v in p.steps_start.iteritems():
> +            if start == 0 or v < start:
> +                start = v
> +            if end < v:
> +                end = v
> +
> +    # Readjust all timestamps so that 0 is the start of the build
> +    # instead of being Epoch
> +    for p in data:
> +        for k, v in p.steps_start.iteritems():
> +            p.steps_start[k] = v - start
> +        for k, v in p.steps_end.iteritems():
> +            p.steps_end[k] = v - start
> +
> +    plt.figure()
> +
> +    i = 0
> +    labels_names = []
> +    labels_coords = []
> +    # reversing the list, because the packages build first appear last in the list
> +    for p in reversed(data):
> +        durations = []
> +        colors = []
> +        for step in steps:
> +            if not step in p.steps_start or not step in p.steps_end:
> +                continue
> +            durations.append((p.steps_start[step],
> +                              p.steps_end[step] - p.steps_start[step]))
> +            colors.append(step_colors[step])
> +        plt.broken_barh(durations, (i, 6), facecolors=colors)
> +        labels_coords.append(i + 3)
> +        labels_names.append(p.name)
> +        i += 10
> +
> +    axes = plt.gcf().gca()
> +
> +    axes.set_ylim(0, i + 10)
> +    axes.set_xlim(0, end - start)
> +    axes.set_xlabel('seconds since start')
> +    axes.set_yticks(labels_coords)
> +    axes.set_yticklabels(labels_names)
> +    axes.set_axisbelow(True)
> +    axes.grid(True, linewidth=0.2, zorder=-1)
> +
> +    plt.gcf().subplots_adjust(left=0.2)
> +
> +    plt.tick_params(axis='y', which='both', labelsize=6)
> +    plt.title('Timeline')
> +    plt.savefig(output, dpi=300)
>
>  # Parses the csv file passed on standard input and returns a list of
>  # Package objects, filed with the duration of each step and the total
> @@ -277,7 +344,7 @@ def read_data(input_file):
>
>  parser = argparse.ArgumentParser(description='Draw build time graphs')
>  parser.add_argument("--type", '-t', metavar="GRAPH_TYPE",
> -                    help="Type of graph (histogram, pie-packages, pie-steps)")
> +                    help="Type of graph (histogram, pie-packages, pie-steps, timeline)")
>  parser.add_argument("--order", '-O', metavar="GRAPH_ORDER",
>                      help="Ordering of packages: build or duration (for histogram only)")
>  parser.add_argument("--alternate-colors", '-c', action="store_true",
> @@ -307,6 +374,8 @@ elif args.type == "pie-packages":
>      pkg_pie_time_per_package(d, args.output)
>  elif args.type == "pie-steps":
>      pkg_pie_time_per_step(d, args.output)
> +elif args.type == "timeline":
> +    pkg_timeline(d, args.output)
>  else:
>      sys.stderr.write("Unknown type: %s\n" % args.type)
>      exit(1)
> --
> 2.14.4
>
> _______________________________________________
> buildroot mailing list
> buildroot at busybox.net
> http://lists.busybox.net/mailman/listinfo/buildroot



-- 
Matthew L Weber / Pr Software Engineer
Airborne Information Systems / RC Linux Secure Platforms
MS 131-100, C Ave NE, Cedar Rapids, IA, 52498, USA
www.rockwellcollins.com

Note: Any Export License Required Information and License Restricted
Third Party Intellectual Property (TPIP) content must be encrypted and
sent to matthew.weber at corp.rockwellcollins.com.

[Buildroot] [PATCH 2/2] support/scripts/graph-build-time: add support for timeline graphing

[Thomas Petazzoni]

Hello,

On Sat, 22 Sep 2018 08:47:54 -0500, Matthew Weber wrote:

> > The graph-build make target is extended to also generate this new
> > timeline graph.  
> 
> Is there a way to remove the page boundary or split the data so larger
> builds are readable?  I'm not sure of the readablility point but my
> build test of ~80-100pkg target was overlapping.

There should be no page boundary, but I indeed haven't tested yet
larger builds, and the script may need additional tweaks.

I'll try with some larger build and see if I can improve the script.

Best regards,

Thomas
-- 
Thomas Petazzoni, CTO, Bootlin
Embedded Linux and Kernel engineering
https://bootlin.com