Proposal - Show repeated commands as separate positions

[robd]

Currently, if you call the same command multiple times, airbrussh doesn't really print out the right thing.
Below is some sample output, which I've annotated with the problems as I see them:

on_local("repeated_command_test") do
  execute(:echo, "command 1")
  execute(:echo, "command 1")
  execute(:echo, "command 2")
  execute(:echo, "command 1")
end

# output_lines :
  "      01 echo command 1\n",
  "      01 command 1\n",
  "    ✔ 01 test_user@localhost 0.004s\n",
# Missing start line and position number not incremented for Command 1 the second time
  "      01 command 1\n", # Wrong position number for stdout, should be 2
  "    ✔ 01 test_user@localhost 0.004s\n", # Wrong position number for end line
  "      02 echo command 2\n",
  "      02 command 2\n",
  "    ✔ 02 test_user@localhost 0.003s\n",
# Missing start line and position number goes back to 1 for Command 1 the third time
  "      01 command 1\n", # Wrong position number for stdout, should be 4
  "    ✔ 01 test_user@localhost 0.004s\n" # Wrong position number for end line

I propose to increment the command position in these cases, so it's clear which instance of the command the output belongs to. In order to achieve this, I'm thinking we could rely on the command uuid and enhance the command history to store all command executions, even if they have the same command string.

My idea is to modify the command history so it is never cleared. It would therefore be a complete command history rather than just being the history for the most recent task. I would store each command, in order as they are started. I would also store the current rake task against each command at the time the command is started.

I would then reimplement the methods which rely on the command history (eg first_execution, position, etc) using the new full command history.

As well as supporting repeated commands, I think this would make the code easier to reason about. At the moment I find the behaviour to do with clearing the history, storing the last task name and adding new commands hard to understand.

@mattbrictson Does this make sense? Should I look into this?

[mattbrictson]

@robd Please hold off on this one for now, as I think some more discussion is needed. I am worried that this changes what I consider desirable behavior for multi-server deployments, where the same command running on multiple servers share the same number prefix.

When e.g. running echo foo on three servers, I think I prefer this:

  01 echo foo
✔ 01 user@server1 0.004s
✔ 01 user@server2 0.004s
✔ 01 user@server3 0.004s

Rather than:

  01 echo foo
✔ 01 user@server1 0.004s
  02 echo foo
✔ 02 user@server2 0.004s
  03 echo foo
✔ 03 user@server3 0.004s

In my mind, it is one command, three executions rather than three separate commands (even though it really is three distinct command UUIDs behind the scenes). That is why airbrussh currently compares commands using to_s rather than UUID.

That said, I agree that if you did run the same command three times in a row on one server, that the output is not ideal. However I consider that a fairly uncommon scenario. Right now to_s is kind of a blunt instrument that doesn't allow us to distinguish duplicate commands from multi-server executions of the same command.

[robd]

Ah OK I see - that makes sense, and I agree

I guess I am just unfortunate in that I happen to see this during my deployments:

01:05 nginx:install
      Downloading nginx.conf.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      01 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/nginx.conf
    ✔ 01 [email protected] 0.289s
      02 sudo rm /tmp/tmp.conf
    ✔ 02 [email protected] 0.250s
      Downloading mime.types.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      03 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/mime.types
    ✔ 03 [email protected] 0.144s
    ✔ 02 [email protected] 0.144s
      04 sudo install -m 0600 /var/www/domain/current/config/nginx/ssl/certs/www.domain.co.uk.crt /etc/ssl/certs/www.domain.co.uk.crt
    ✔ 04 [email protected] 0.172s
      05 sudo install -m 0600 /var/www/domain/current/config/nginx/ssl/private/www.domain.co.uk.key /etc/ssl/private/www.domain.co.uk.key
    ✔ 05 [email protected] 0.155s
      Downloading nginx-vhosts.conf.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      06 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/sites-available/domain_staging.conf
    ✔ 06 [email protected] 0.162s
    ✔ 02 [email protected] 0.150s
      07 sudo rm -f /etc/nginx/sites-enabled/domain_staging.conf
    ✔ 07 [email protected] 0.150s
      08 sudo ln -s /etc/nginx/sites-available/domain_staging.conf /etc/nginx/sites-enabled/domain_staging.conf
    ✔ 08 [email protected] 0.153s
      Downloading nginx.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      09 sudo install -m 0600 /tmp/tmp.conf /etc/logrotate.d/nginx
    ✔ 09 [email protected] 0.193s
    ✔ 02 [email protected] 0.158s

Output with #54:

01:08 nginx:install
      Downloading nginx.conf.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      01 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/nginx.conf
    ✔ 01 [email protected] 0.164s
      02 sudo rm /tmp/tmp.conf
    ✔ 02 [email protected] 0.156s
      Downloading mime.types.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      03 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/mime.types
    ✔ 03 [email protected] 0.157s
      04 sudo rm /tmp/tmp.conf
    ✔ 04 [email protected] 0.161s
      05 sudo install -m 0600 /var/www/domain/current/config/nginx/ssl/certs/www.domain.co.uk.crt /etc/ssl/certs/www.domain.co.uk.crt
    ✔ 05 [email protected] 0.165s
      06 sudo install -m 0600 /var/www/domain/current/config/nginx/ssl/private/www.domain.co.uk.key /etc/ssl/private/www.domain.co.uk.key
    ✔ 06 [email protected] 0.160s
      Downloading nginx-vhosts.conf.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      07 sudo install -m 0600 /tmp/tmp.conf /etc/nginx/sites-available/domain_staging.conf
    ✔ 07 [email protected] 0.157s
      08 sudo rm /tmp/tmp.conf
    ✔ 08 [email protected] 0.153s
      09 sudo rm -f /etc/nginx/sites-enabled/domain_staging.conf
    ✔ 09 [email protected] 0.150s
      10 sudo ln -s /etc/nginx/sites-available/domain_staging.conf /etc/nginx/sites-enabled/domain_staging.conf
    ✔ 10 [email protected] 0.139s
      Downloading nginx.erb 100.0%
      Uploading /tmp/tmp.conf 100.0%
      11 sudo install -m 0600 /tmp/tmp.conf /etc/logrotate.d/nginx
    ✔ 11 [email protected] 0.162s
      12 sudo rm /tmp/tmp.conf
    ✔ 12 [email protected] 0.206s

As you can see, it's quite misleading at the moment. There are 12 commands, not 9 as reported by Airbrussh, and the order of command completions isn't ideal. Obviously I could fix this by using a different temporary filename, but I think it would be better if I didn't have to code round Airbrussh.

I now understand what first_execution means! This is intended to mean 'is it executing on the first server?' as opposed to 'is this a repeat command?'.

I guess this is non trivial to fix. Do I remember you saying that the command is duplicated for each server? I guess it must be in order to store separate command output etc.

As I see it there are 2 responsibilities needed from the history:

1. first_execution?(command) aka executed_on_another_server?
2. position(command)

For me, the ideal fix would be to split the Command and CommandExecution objects in SSHKit so that in the formatter you get a CommandExecution which has a @command attribute. We would no longer duplicate the Command and all CommandExecutions would point to the same Command so you wouldn't get multiple UUIDs. I think this would make #54 work as intended.

[mattbrictson]

I now understand what first_execution means! This is intended to mean 'is it executing on the first server?' as opposed to 'is this a repeat command?'.

Exactly!

For me, the ideal fix would be to split the Command and CommandExecution objects in SSHKit so that in the formatter you get a CommandExecution which has a @command attribute.

Yes, that was my thought as well.

Without that change, I don't think there is enough information in the current Command object to distinguish a duplicate command from multi-server execution.

[robd]

Without that change, I don't think there is enough information in the current Command object to distinguish a duplicate command from multi-server execution.

No, I agree. I thought of a couple of workarounds, such as hooking SSHKit / Capistrano to detect if there are multiple hosts, or moving into 'multiple host' matching mode once we spot a different host on a command. But I think it would be cleaner just to fix this in SSHKit.

Just out of interest - do you use Airbrussh on multiple hosts day to day? I never have, so I always forget about this (common) use case.

[mattbrictson]

Just out of interest - do you use Airbrussh on multiple hosts day to day? I never have, so I always forget about this (common) use case.

Yes, right now I have two active projects that use multi-server production environments: one with 3 servers (app, db, worker), and one with 2 (app, db).

[pblesi]

Would ignoring only consecutive executions work as a viable workaround for this? It may not be bullet-proof, but it seems like an improvement on the current implementation?