Align profiling times for better readability

Before we would write:

    lib/foo.ex compiled in 10ms (plus 100ms waiting)

However, because the file name is variable, it was
hard to see which file took the longest. Now we will
write:

        10ms compiling +    100ms waiting for lib/foo.ex

By right aligning all times, we can easily look in
the first row and see which file took the longest.
We can also provide a summary option in the future,
if necessary.

Author: josevalim

lib/elixir/lib/kernel/parallel_compiler.ex

@@ -623,13 +623,13 @@ defmodule Kernel.ParallelCompiler do
         data = maybe_warn_long_compilation(data, state)
 
         if state.profile != :none do
-          compiling = System.convert_time_unit(data.compiling, :native, :millisecond)
-          waiting = System.convert_time_unit(data.waiting, :native, :millisecond)
-          extra = if waiting > 0, do: " (plus #{waiting}ms waiting)", else: ""
+          compiling = to_padded_ms(data.compiling)
+          waiting = to_padded_ms(data.waiting)
+          relative = Path.relative_to_cwd(data.file)
 
           IO.puts(
             :stderr,
-            "[profile] #{Path.relative_to_cwd(data.file)} compiled in #{compiling}ms" <> extra
+            "[profile] #{compiling}ms compiling + #{waiting}ms waiting for #{relative}"
           )
         end
 
@@ -640,6 +640,13 @@ defmodule Kernel.ParallelCompiler do
     end)
   end
 
+  defp to_padded_ms(time) do
+    time
+    |> System.convert_time_unit(:native, :millisecond)
+    |> Integer.to_string()
+    |> String.pad_leading(6, " ")
+  end
+
   defp discard_down(pid) do
     receive do
       {:DOWN, _, :process, ^pid, _} -> :ok

lib/elixir/test/elixir/kernel/parallel_compiler_test.exs

@@ -43,7 +43,9 @@ defmodule Kernel.ParallelCompilerTest do
           assert HelloWorld in modules
         end)
 
-      assert profile =~ ~r"\[profile\] .*tmp/profile_time/bar.ex compiled in \d+ms"
+      assert profile =~
+               ~r"\[profile\] [\s\d]{6}ms compiling \+      0ms waiting for .*tmp/profile_time/bar.ex"
+
       assert profile =~ ~r"\[profile\] Finished compilation cycle of 1 modules in \d+ms"
       assert profile =~ ~r"\[profile\] Finished group pass check of 1 modules in \d+ms"
     after