bitwalker/distillery

The output of `bin/myapp describe` is racy

alco opened this issue · 2 comments

alco commented

The race is happening when printing Hooks and Custom commands. Here's one invocation of bin/myapp describe:

Hooks =================================
post_configure.d:
post_start.d:
    No post_configure.d hooks defined
post_stop.d:
post_upgrade.d:
    No post_start.d hooks defined
    No post_stop.d hooks defined
pre_configure.d:
    No post_upgrade.d hooks defined
    set_pod_a_record.sh
pre_start.d:
    No pre_start.d hooks defined
pre_stop.d:
    No pre_stop.d hooks defined
pre_upgrade.d:
    No pre_upgrade.d hooks defined

Custom Commands =======================
ecto.create
ecto.migrate
ecto.see

Here's another one:

Hooks =================================
post_configure.d:
post_start.d:
post_stop.d:
    No post_configure.d hooks defined
    No post_start.d hooks defined
post_upgrade.d:
pre_configure.d:
    set_pod_a_record.sh
    No post_stop.d hooks defined
    No post_upgrade.d hooks defined
pre_start.d:
    No pre_start.d hooks defined
pre_stop.d:
    No pre_stop.d hooks defined
pre_upgrade.d:

Custom Commands =======================
    No pre_upgrade.d hooks defined
ecto.create
ecto.migrate
ecto.seed

I believe the problem is that Erlang's :stdio and :standard_error devices and not synchronized, so one can output data concurrently with the other. Not sure if it's OS-specific, I'm running the release on Alpine Linux (Kernel version 4.15.0). Distillery version: 2.0.12.

In this code from Artificery

distillery/lib/mix/lib/releases/runtime/control.ex

Lines 232 to 245 in ed4deb7

for {group, hooks} <- fetch_hooks(opts) do
Console.info("#{group}:")
if length(hooks) > 0 do
{hook_width, doc_width} = column_widths(hooks)
for {hook, doc} <- hooks do
IO.write([" ", IO.ANSI.green(), hook, IO.ANSI.reset(), String.duplicate(" ", max(hook_width - byte_size(hook) + 2, 2))])
print_help_lines(doc, doc_width + 1)
end
else
Console.warn(" No #{group} hooks defined")
end
end

Console.info calls IO.write(:stdio, ...) and Console.warn calls IO.write(:standard_error, ...), that's why they are stepping on each other's toes.

alco commented

Another occurrence of this race:

==> Running validation checks..
    > Mix.Releases.Checks.Erts * WARN

    > Mix.Releases.Checks.Cookie * PASS
    > Mix.Releases.Checks.LoadedOrphanedApps * PASS
IMPORTANT: You have opted to *not* include the Erlang runtime system (ERTS).
You must ensure that the version of Erlang this release is built with matches
the version the release will be run with once deployed. It will fail to run otherwise.
bitwalker commented

Thanks! I've updated Artificery to provide a bit more control here and use :stdio by default for all output