Use same sentence style as broadcasts for audit log lines

* main:
  Remove unnecessary audit recordings

README.md

@@ -20,7 +20,9 @@ env:
     - RAILS_MASTER_KEY
 ```
 
-Then edit your `.env` file to add your registry password as `MRSK_REGISTRY_PASSWORD` (and your `RAILS_MASTER_KEY` for production with a Rails app).
+Then edit your `.env` file to add your registry password as `MRSK_REGISTRY_PASSWORD` (and your `RAILS_MASTER_KEY` for production with a Rails app). 
+
+Finally, you have to ensure your application can answer `200 OK` to a `GET /up` request. That's how the zero-downtime deploy process knows that your new version is ready to serve traffic.
 
 Now you're ready to deploy to the servers:
 
@@ -345,6 +347,29 @@ This template can safely be checked into git. Then everyone deploying the app ca
 
 If you need separate env variables for different destinations, you can set them with `.env.destination.erb` for the template, which will generate `.env.staging` when run with `mrsk envify -d staging`.
 
+### Using audit broadcasts
+
+If you'd like to broadcast audits of deploys, rollbacks, etc to a chatroom or elsewhere, you can configure the `audit_broadcast_cmd` setting with the path to a bin file that reads the audit line from STDIN, and then does whatever with it:
+
+```yaml
+audit_broadcast_cmd:
+  bin/audit_broadcast
+```
+
+The broadcast command could look something like:
+
+```bash
+#!/usr/bin/env bash
+read
+curl -q -d content="[My app] ${REPLY}" https://3.basecamp.com/XXXXX/integrations/XXXXX/buckets/XXXXX/chats/XXXXX/lines
+```
+
+That'll post a line like follows to a preconfigured chatbot in Basecamp:
+
+```
+[My App] [2023-02-18 11:29:52] [dhh] Rolled back to version d264c4e92470ad1bd18590f04466787262f605de
+```
+
 ## Commands
 
 ### Running commands on servers

lib/mrsk/cli/accessory.rb

@@ -9,9 +9,11 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
         upload(name)
 
         on(accessory.host) do
-          execute *MRSK.auditor.record("accessory #{name} boot"), verbosity: :debug
+          execute *MRSK.auditor.record("Booted #{name} accessory"), verbosity: :debug
           execute *accessory.run
         end
+
+        audit_broadcast "Booted accessory #{name}"
       end
     end
   end
@@ -20,8 +22,6 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def upload(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} upload files"), verbosity: :debug
-
         accessory.files.each do |(local, remote)|
           accessory.ensure_local_file_present(local)
 
@@ -37,8 +37,6 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def directories(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} create directories"), verbosity: :debug
-
         accessory.directories.keys.each do |host_path|
           execute *accessory.make_directory(host_path)
         end
@@ -59,7 +57,7 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def start(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} start"), verbosity: :debug
+        execute *MRSK.auditor.record("Started #{name} accessory"), verbosity: :debug
         execute *accessory.start
       end
     end
@@ -69,7 +67,7 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def stop(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} stop"), verbosity: :debug
+        execute *MRSK.auditor.record("Stopped #{name} accessory"), verbosity: :debug
         execute *accessory.stop, raise_on_non_zero_exit: false
       end
     end
@@ -111,14 +109,14 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
       when options[:reuse]
         say "Launching command from existing container...", :magenta
         on(accessory.host) do
-          execute *MRSK.auditor.record("accessory #{name} cmd '#{cmd}'"), verbosity: :debug
+          execute *MRSK.auditor.record("Executed cmd '#{cmd}' on #{name} accessory"), verbosity: :debug
           capture_with_info(*accessory.execute_in_existing_container(cmd))
         end
 
       else
         say "Launching command from new container...", :magenta
         on(accessory.host) do
-          execute *MRSK.auditor.record("accessory #{name} cmd '#{cmd}'"), verbosity: :debug
+          execute *MRSK.auditor.record("Executed cmd '#{cmd}' on #{name} accessory"), verbosity: :debug
           capture_with_info(*accessory.execute_in_new_container(cmd))
         end
       end
@@ -169,7 +167,7 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def remove_container(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} remove container"), verbosity: :debug
+        execute *MRSK.auditor.record("Remove #{name} accessory container"), verbosity: :debug
         execute *accessory.remove_container
       end
     end
@@ -179,7 +177,7 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def remove_image(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} remove image"), verbosity: :debug
+        execute *MRSK.auditor.record("Removed #{name} accessory image"), verbosity: :debug
         execute *accessory.remove_image
       end
     end
@@ -189,7 +187,6 @@ class Mrsk::Cli::Accessory < Mrsk::Cli::Base
   def remove_service_directory(name)
     with_accessory(name) do |accessory|
       on(accessory.host) do
-        execute *MRSK.auditor.record("accessory #{name} remove service directory"), verbosity: :debug
         execute *accessory.remove_service_directory
       end
     end

lib/mrsk/cli/app.rb

@@ -7,7 +7,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
 
       MRSK.config.roles.each do |role|
         on(role.hosts) do |host|
-          execute *MRSK.auditor.record("app boot version #{version}"), verbosity: :debug
+          execute *MRSK.auditor.record("Booted app version #{version}"), verbosity: :debug
 
           begin
             execute *MRSK.app.stop, raise_on_non_zero_exit: false
@@ -15,7 +15,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
           rescue SSHKit::Command::Failed => e
             if e.message =~ /already in use/
               error "Rebooting container with same version already deployed on #{host}"
-              execute *MRSK.auditor.record("app rebooted with version #{version}"), verbosity: :debug
+              execute *MRSK.auditor.record("Rebooted app version #{version}"), verbosity: :debug
 
               execute *MRSK.app.remove_container(version: version)
               execute *MRSK.app.run(role: role.name)
@@ -31,7 +31,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
   desc "start", "Start existing app on servers (use --version=<git-hash> to designate specific version)"
   def start
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("app start version #{MRSK.version}"), verbosity: :debug
+      execute *MRSK.auditor.record("Started app version #{MRSK.version}"), verbosity: :debug
       execute *MRSK.app.start, raise_on_non_zero_exit: false
     end
   end
@@ -39,7 +39,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
   desc "stop", "Stop app on servers"
   def stop
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("app stop"), verbosity: :debug
+      execute *MRSK.auditor.record("Stopped app"), verbosity: :debug
       execute *MRSK.app.stop, raise_on_non_zero_exit: false
     end
   end
@@ -74,7 +74,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
         say "Launching command with version #{version} from existing container...", :magenta
 
         on(MRSK.hosts) do |host|
-          execute *MRSK.auditor.record("app cmd '#{cmd}' with version #{version}"), verbosity: :debug
+          execute *MRSK.auditor.record("Executed cmd '#{cmd}' on app version #{version}"), verbosity: :debug
           puts_by_host host, capture_with_info(*MRSK.app.execute_in_existing_container(cmd))
         end
       end
@@ -84,7 +84,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
       using_version(options[:version] || most_recent_version_available) do |version|
         say "Launching command with version #{version} from new container...", :magenta
         on(MRSK.hosts) do |host|
-          execute *MRSK.auditor.record("app cmd '#{cmd}' with version #{version}"), verbosity: :debug
+          execute *MRSK.auditor.record("Executed cmd '#{cmd}' on app version #{version}"), verbosity: :debug
           puts_by_host host, capture_with_info(*MRSK.app.execute_in_new_container(cmd))
         end
       end
@@ -140,7 +140,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
   desc "remove_container [VERSION]", "Remove app container with given version from servers"
   def remove_container(version)
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("app remove container #{version}"), verbosity: :debug
+      execute *MRSK.auditor.record("Removed app container with version #{version}"), verbosity: :debug
       execute *MRSK.app.remove_container(version: version)
     end
   end
@@ -148,7 +148,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
   desc "remove_containers", "Remove all app containers from servers"
   def remove_containers
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("app remove containers"), verbosity: :debug
+      execute *MRSK.auditor.record("Removed all app containers"), verbosity: :debug
       execute *MRSK.app.remove_containers
     end
   end
@@ -156,7 +156,7 @@ class Mrsk::Cli::App < Mrsk::Cli::Base
   desc "remove_images", "Remove all app images from servers"
   def remove_images
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("app remove images"), verbosity: :debug
+      execute *MRSK.auditor.record("Removed all app images"), verbosity: :debug
       execute *MRSK.app.remove_images
     end
   end

lib/mrsk/cli/base.rb

@@ -59,9 +59,14 @@ module Mrsk::Cli
       def print_runtime
         started_at = Time.now
         yield
+        return Time.now - started_at
       ensure
         runtime = Time.now - started_at
         puts "  Finished all in #{sprintf("%.1f seconds", runtime)}"
       end
+
+      def audit_broadcast(line)
+        run_locally { execute *MRSK.auditor.broadcast(line), verbosity: :debug }
+      end
   end
 end

lib/mrsk/cli/build.rb

@@ -29,7 +29,7 @@ class Mrsk::Cli::Build < Mrsk::Cli::Base
   desc "pull", "Pull app image from the registry onto servers"
   def pull
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("build pull image #{MRSK.version}"), verbosity: :debug
+      execute *MRSK.auditor.record("Pulled image with version #{MRSK.version}"), verbosity: :debug
       execute *MRSK.builder.pull
     end
   end

lib/mrsk/cli/main.rb

@@ -10,7 +10,7 @@ class Mrsk::Cli::Main < Mrsk::Cli::Base
 
   desc "deploy", "Deploy the app to servers"
   def deploy
-    print_runtime do
+    runtime = print_runtime do
       say "Ensure Docker is installed...", :magenta
       invoke "mrsk:cli:server:bootstrap"
 
@@ -28,16 +28,20 @@ class Mrsk::Cli::Main < Mrsk::Cli::Base
       say "Prune old containers and images...", :magenta
       invoke "mrsk:cli:prune:all"
     end
+
+    audit_broadcast "Deployed in #{runtime.to_i} seconds"
   end
 
   desc "redeploy", "Deploy new version of the app to servers (without bootstrapping servers, starting Traefik, pruning, and registry login)"
   def redeploy
-    print_runtime do
+    runtime = print_runtime do
       say "Build and push app image...", :magenta
       invoke "mrsk:cli:build:deliver"
 
       invoke "mrsk:cli:app:boot"
     end
+
+    audit_broadcast "Redeployed in #{runtime.to_i} seconds"
   end
 
   desc "rollback [VERSION]", "Rollback the app to VERSION"
@@ -51,6 +55,8 @@ class Mrsk::Cli::Main < Mrsk::Cli::Base
       execute *MRSK.app.stop, raise_on_non_zero_exit: false
       execute *MRSK.app.start
     end
+
+    audit_broadcast "Rolled back to version #{version}"
   end
 
   desc "details", "Display details about Traefik and app containers"

lib/mrsk/cli/prune.rb

@@ -5,10 +5,10 @@ class Mrsk::Cli::Prune < Mrsk::Cli::Base
     invoke :images
   end
 
-  desc "images", "Prune unused images older than 30 days"
+  desc "images", "Prune unused images older than 7 days"
   def images
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("prune images"), verbosity: :debug
+      execute *MRSK.auditor.record("Pruned images"), verbosity: :debug
       execute *MRSK.prune.images
     end
   end
@@ -16,7 +16,7 @@ class Mrsk::Cli::Prune < Mrsk::Cli::Base
   desc "containers", "Prune stopped containers for the service older than 3 days"
   def containers
     on(MRSK.hosts) do
-      execute *MRSK.auditor.record("prune containers"), verbosity: :debug
+      execute *MRSK.auditor.record("Pruned containers"), verbosity: :debug
       execute *MRSK.prune.containers
     end
   end

lib/mrsk/cli/traefik.rb

@@ -14,7 +14,7 @@ class Mrsk::Cli::Traefik < Mrsk::Cli::Base
   desc "start", "Start existing Traefik on servers"
   def start
     on(MRSK.traefik_hosts) do
-      execute *MRSK.auditor.record("traefik start"), verbosity: :debug
+      execute *MRSK.auditor.record("Started traefik"), verbosity: :debug
       execute *MRSK.traefik.start, raise_on_non_zero_exit: false
     end
   end
@@ -22,7 +22,7 @@ class Mrsk::Cli::Traefik < Mrsk::Cli::Base
   desc "stop", "Stop Traefik on servers"
   def stop
     on(MRSK.traefik_hosts) do
-      execute *MRSK.auditor.record("traefik stop"), verbosity: :debug
+      execute *MRSK.auditor.record("Stopped traefik"), verbosity: :debug
       execute *MRSK.traefik.stop, raise_on_non_zero_exit: false
     end
   end
@@ -72,7 +72,7 @@ class Mrsk::Cli::Traefik < Mrsk::Cli::Base
   desc "remove_container", "Remove Traefik container from servers"
   def remove_container
     on(MRSK.traefik_hosts) do
-      execute *MRSK.auditor.record("traefik remove container"), verbosity: :debug
+      execute *MRSK.auditor.record("Removed traefik container"), verbosity: :debug
       execute *MRSK.traefik.remove_container
     end
   end
@@ -80,7 +80,7 @@ class Mrsk::Cli::Traefik < Mrsk::Cli::Base
   desc "remove_container", "Remove Traefik image from servers"
   def remove_image
     on(MRSK.traefik_hosts) do
-      execute *MRSK.auditor.record("traefik remove image"), verbosity: :debug
+      execute *MRSK.auditor.record("Removed traefik image"), verbosity: :debug
       execute *MRSK.traefik.remove_image
     end
   end

lib/mrsk/commands/auditor.rb

@@ -1,12 +1,22 @@
 require "active_support/core_ext/time/conversions"
 
 class Mrsk::Commands::Auditor < Mrsk::Commands::Base
+  # Runs remotely
   def record(line)
     append \
       [ :echo, tagged_line(line) ],
       audit_log_file
   end
 
+  # Runs locally
+  def broadcast(line)
+    if broadcast_cmd = config.audit_broadcast_cmd
+      pipe \
+        [ :echo, tagged_line(line) ],
+        broadcast_cmd
+    end
+  end
+
   def reveal
     [ :tail, "-n", 50, audit_log_file ]
   end
@@ -21,14 +31,14 @@ class Mrsk::Commands::Auditor < Mrsk::Commands::Base
     end
 
     def tags
-      "[#{timestamp}] [#{performer}]"
+      "[#{recorded_at}] [#{performer}]"
     end
 
     def performer
-      `whoami`.strip
+      @performer ||= `whoami`.strip
     end
 
-    def timestamp
+    def recorded_at
       Time.now.to_fs(:db)
     end
 end

lib/mrsk/commands/prune.rb

@@ -2,14 +2,11 @@ require "active_support/duration"
 require "active_support/core_ext/numeric/time"
 
 class Mrsk::Commands::Prune < Mrsk::Commands::Base
-  PRUNE_IMAGES_AFTER     = 7.days.in_hours.to_i
-  PRUNE_CONTAINERS_AFTER = 3.days.in_hours.to_i
-
-  def images
-    docker :image, :prune, "--all", "--force", "--filter", "label=service=#{config.service}", "--filter", "until=#{PRUNE_IMAGES_AFTER}h"
+  def images(until_hours: 7.days.in_hours.to_i)
+    docker :image, :prune, "--all", "--force", "--filter", "label=service=#{config.service}", "--filter", "until=#{until_hours}h"
   end
 
-  def containers
-    docker :container, :prune, "--force", "--filter", "label=service=#{config.service}", "--filter", "until=#{PRUNE_CONTAINERS_AFTER}h"
+  def containers(until_hours: 3.days.in_hours.to_i)
+    docker :container, :prune, "--force", "--filter", "label=service=#{config.service}", "--filter", "until=#{until_hours}h"
   end
 end

lib/mrsk/configuration.rb

@@ -126,6 +126,10 @@ class Mrsk::Configuration
     { user: ssh_user, proxy: ssh_proxy, auth_methods: [ "publickey" ] }.compact
   end
 
+  def audit_broadcast_cmd
+    raw_config.audit_broadcast_cmd
+  end
+
 
   def valid?
     ensure_required_keys_present && ensure_env_available

test/commands/auditor_test.rb

@@ -0,0 +1,27 @@
+require "test_helper"
+
+class CommandsAuditorTest < ActiveSupport::TestCase
+  setup do
+    @config = {
+      service: "app", image: "dhh/app", registry: { "username" => "dhh", "password" => "secret" }, servers: [ "1.1.1.1" ],
+      audit_broadcast_cmd: "bin/audit_broadcast"
+    }
+  end
+
+  test "record" do
+    assert_match \
+      /echo '.* app removed container' >> mrsk-app-audit.log/,
+      new_command.record("app removed container").join(" ")
+  end
+
+  test "broadcast" do
+    assert_match \
+      /echo '.* app removed container' \| bin\/audit_broadcast/,
+      new_command.broadcast("app removed container").join(" ")
+  end
+
+  private
+    def new_command
+      Mrsk::Commands::Auditor.new(Mrsk::Configuration.new(@config, version: "123"))
+    end
+end