Forem: Mariusz Hausenplas

Automated on-demand deployments with Semaphore CI Classic API (and Ruby)

Mariusz Hausenplas — Mon, 11 May 2020 18:02:27 +0000

Semaphore is a popular tool used to create CI/CD pipelines. It does a great job at quickly integrating with Git repositories and running build or deployment tasks. Additionally, it comes with two different flavours: the standard Semaphore Classic and, the much more sophisticated Semaphore 2.0.

While I'm not fully familiar with Semaphore 2.0 capabilities, one thing I can tell about Semaphore Classic is that it feels like one of the good, old Unix programs that was designed to do one simple thing, and do it well. Or, perhaps more accurately, it feels like a tool that was built with the Convention over Configuration rule in mind: it can definitely do a lot of things, but only in a specific way, and under specific assumptions.

In this post I'll explore the surprisingly underdocumented capabilities of Semaphore Classic HTTP API to create a custom workflow supporting on-demand deployments to different servers.

Now, imagine you've submitted a pull request and you'd like to test it somehow, e.g. on a staging environment. At this point you've probably already defined a new staging server that Semaphore could deploy to. So, all you have to do is to select a branch, pick a build and click Deploy manually and select your non-production server. Pretty easy, eh? Well, what if you misclicked and accidentally deployed to production? Of course you could count on your reflexes and instantly stop the deploy, but we all know that it's better to automate such risky processes. Human error is inevitable. So where do we start?

Semaphore CI operates on a small number of easy-to-comprehend concepts: Branches, Builds, Servers and Deploys. As we saw in the previous paragraph, a build is triggered by some kind of an external event (e.g. by a new brach being created or a new pull request being submitted). Then, you'd usually want CI to deploy this build to a specific server. These concepts map to entities in the HTTP API:

With this knowledge in mind, let's try to automate something!

URL structure & basic Semaphore API client setup

In this preliminary step, let's create a simple Ruby class that uses the HTTParty gem and lists required configuration variables that'll be passed in requests to Semaphore API.

class SemaphoreClient
  include HTTParty

  PROJECT_ID = ENV["SEMAPHORE_PROJECT_ID"]
  SERVER_ID = ENV["SEMAPHORE_SERVER_ID"]

  base_uri "https://semaphoreci.com/api/v1/projects/#{PROJECT_ID}"

  default_params auth_token: ENV["SEMAPHORE_API_AUTH_TOKEN"]
end

base_uri method defines the root URL of Semaphore Classic API
auth_token param will be passed in every request. This is the User Authentication Token found in Account Settings
PROJECT_ID is an ID of a Semaphore project, corresponding to a Git repository. This is a bit tricky to find: you can either query the Projects API to find your repo, or go to Project Badge Settings where you can copy-paste the ID from provided snippets. This should look something like this: https://semaphoreci.com/api/v1/projects/<project_id>/badge.svg.
SERVER_ID is an ID of a target deployment server, e.g. the one you'd like to use to deploy to your Staging/Preview environment. It seems that the only way to fetch internal IDs of servers is via the Servers API

Check branch build status

First, we need to check if a Semaphore build completed succesfully on a branch. In other words, let's see if the PR is "green" (build passed), "yellow" (build pending) or "red" (build failed):
```
class SemaphoreClient

  ...

  class << self
    def pr_status(pr_number:)
      response = get(
        "/pull-request-#{pr_number}/status"
      )

      {
        build_number: response["build_number"],
        result: response["result"]
      }
    end
  end
end
```
As you can see, calling SemaphoreClient.pr_status("1234") should return a simple hash with build_number and result: we'll need these values for later.
Trigger deployment

If result is "passed", this means that the Semaphore build has passed and can be safely deployed. Of course, it's also possible to deploy a running build (if you're brave enough). Anyway, let's add another method which'll use the build_number that we received in previous call.
```
class SemaphoreClient

  ...

  class << self
    def trigger_deploy(pr_number:, build_number:)
      response = post(
        "/pull-request-#{pr_number}/builds/" \
        "#{build_number}/deploy/#{SERVER_ID}"
      )

      {
        number: response["number"],
        result: response["result"]
      }
    end
  end   
end
```
Ta-da! You've just triggered a deployment to a non-default server without having to click through the Semaphore user interface. Time to pop the champagne?

Check deployment status

Finally, it'd be good to monitor whether a deployment completed successfully. Let's add one more method:

class SemaphoreClient

  ...

  class << self
    def deploy_status(deploy_number:)
      response = get(
        "/servers/#{SERVER_ID}/deploys/#{deploy_number}"
      )

      {
        number: response["number"],
        result: response["result"]
      }
    end
  end
end

And that's it. It's a very simplistic solution, yet should be enough to serve as a proof of concept for futher integration with Github Actions, a Github/Gitlab/Bitbucket bot or any other tool automating your Semaphore CI workflows.

Finally, for the record, here's the entire SemaphoreClient class. Again, please treat it as a basic PoC: it definitely calls for some error handling and, depending on your needs, you might want to fetch more data from the API responses. Anyway, happy integrating with Semaphore!

class SemaphoreClient
  include HTTParty

  PROJECT_ID = ENV["SEMAPHORE_PROJECT_ID"]
  SERVER_ID = ENV["SEMAPHORE_SERVER_ID"]

  base_uri "https://semaphoreci.com/api/v1/projects/#{PROJECT_ID}"

  default_params auth_token: ENV["SEMAPHORE_API_AUTH_TOKEN"]

  class << self
    def pr_status(pr_number:)
      response = get(
        "/pull-request-#{pr_number}/status"
      )

      {
        build_number: response["build_number"],
        result: response["result"]
      }
    end

    def trigger_deploy(pr_number:, build_number:)
      response = post(
        "/pull-request-#{pr_number}/builds/" \
        "#{build_number}/deploy/#{SERVER_ID}"
      )

      {
        number: response["number"],
        result: response["result"]
      }
    end

    def deploy_status(deploy_number:)
      response = get(
        "/servers/#{SERVER_ID}/deploys/#{deploy_number}"
      )

      {
        number: response["number"],
        result: response["result"]
      }
    end
  end
end

Fixing Rails' Action Cable logger

Mariusz Hausenplas — Tue, 21 Apr 2020 18:19:19 +0000

cover photo credit: Niels Heidenreich, https://www.flickr.com/photos/schoschie/282706867
this story was originally published on Medium on Nov 4, 2018, see link

Action Cable has been with us for a couple of years now, and seems to be doing a pretty good job at being a simple, out-of-the-box Rails-driven Web Sockets solution. While it’s not as mature as Rails’ standard REST interface, it actually rather seamlessly, just as it should.

However, when developing Action Cable projects you might have noticed its “interesting” approach towards logging. After making a couple of Web Socket requests to your Action Cable backend, you may see a rather loose and chaotic stream of logs, all fired at different phases of request/response handling and lacking a common structure. The “standard” Rails REST middleware has become a subject of criticism and gems such as Lograge openly define themselves as

“attempting to bring sanity to Rails’ noisy and unusable, unparsable (…) default logging output.”

And, well, Action Cable is also affected.

So let’s have a look. Here are a few logs generated by Action Cable during the opening of Web Sockets connection, subscribing to a channel and calling a Web Socket method:

GET "/ws" [WebSocket] for 127.0.0.1 at 2018-11-03 18:25:00 +0200
Successfully upgraded to WebSocket (REQUEST_METHOD: GET, HTTP_CONNECTION: Upgrade, HTTP_UPGRADE: websocket)

...

ApiChannel is streaming from api:c0f1054d-3e2e-47be-bef0-9d66f3f2ac70

...

[ActionCable] Broadcasting to api:41196d5e-cab3-4fa3-bbef-9b5d400caae7: {:params=>{:my_key=>"my_value", :current_status=>"online"}}

That looks pretty wild. There are request data logged here and there, but in other cases we’re left with vague debug-like messages which aren’t really informative. Honestly speaking, it looks rather random. Or does it? Here are some examples from the source code:

# action_cable/connection/subscriptions.rb

logger.error "Received unrecognized command in #{data.inspect}"

# action_cable/channel/base.rb

logger.error "Unable to process #{action_signature(action, data)}"

# action_cable/connection/message_buffer.rb

connection.logger.error "Couldn't handle non-string message: #{message.class}"

Well, it kind of does. Almost feels as if somebody forgot to remove his/her own development-only debug logs. Unfortunately, multiple Action Cable source code files are littered with those arbitrary logger calls. So how do we fix it? First, let's think about how we can silence all unnecessary logs.

Silencing Action Cable logs

Option 1 (bad): Monkey-patch everything.

Taking advantage of capabilities of Ruby, we can reopen Action Cable methods and remove/adjust all redundant logger calls. Of course, this is tedious and may break whenever there is an update to Action Cable's source code but at the same time, it is least intrusive in a sense that we're not touching the default logger implementation.

Option 2: Try to do it systematically.

Instead of reopening every single Action Cable class in which there is a logger call, we can override the Action Cable logger and set it to a "dummy" instance which doesn't produce any output. To achieve this, add this to your config/application.rb:

ActionCable.server.config.logger = Logger.new(nil)

Obviously you may want to keep default logs in e.g. development only; in such case it’s enough to set this empty logger in config/environments/production.rb or other environment configuration files.

Now, this seems like good enough solution to our problem, but bear in mind that it results with virtually all Action Cable logs being disabled. That includes those already present in e.g. custom Connection and Channel classes defined in your app. To get around it, you may want to change all logger calls (which delegate to ActionCable.server.logger) to the standard Rails.logger invocations. In short:

logger :info, "Authenticating connection"

would have to be changed to

Rails.logger.info "Authenticating connection"

Producing sensible logs

Now, how do we produce sensible logs — e.g. generated whenever a single action finishes processing, just as we’d expect it in REST calls.

Option 1: Monkey-patching (again)

Again, monkey-patching is an option, and it should work fine when you just want to have one or two specific logs, e.g. after every subscription and Web Sockets action being called. Just reopen ActionCable::Connection::Subscriptions#execute_command:

module ActionCable
  module Connection
    class Subscriptions
      def execute_command(data)
        case data["command"]
        when "subscribe"
          add data
          Rails.logger.info "Registered subscription: #{data}"
        when "unsubscribe"
          remove data
          Rails.logger.info "Removed subscription: #{data}"
        when "message"
          perform_action data
          Rails.logger.info "Performed action: #{data}"
        else
          Rails.logger.error "Received unrecognized command in #{data.inspect}"
        end
      rescue Exception => e
        Rails.logger.error "Could not execute command from (#{data.inspect}) [#{e.class} - #{e.message}]: #{e.backtrace.first(5).join(" | ")}"
      end
    end
  end
end

(BTW yes, this e.backtrace.first(5).join(" | ") is in the actual Action Cable source code)

This feels pretty good since we’re only reopening a single method handling multiple types of calls: we killed two birds with one stone by adding logs to subscribe, unsubscribe, message actions, and we're able to produce an error log. Now we can do a couple more tweaks: introduce common payload, calculate processing times etc., but again: this would work until we update Rails and there happens to be a change introduced in this very method, or the method could just be removed because of some refactoring. So can we do better?

Option 2: ActiveSupport::Notifications to the rescue

Thankfully, Rails has introduced the ActiveSupport::Notifications API which can be neatly used to define and subscribe to arbitrary events, defined as blocks of code. There are plenty of guides to ActiveSupport::Notifications, but what's most important to us is that in Action Cable source code itself there already are some pre-instrumented parts of code which we can subscribe to:

ActionCable::Server::Broadcasting includes broadcast.action_cable instrumentation
ActionCable::Channel::Base includes perform_action.action_cable, transmit.action_cable, transmit_subscription_confirmation.action_cable, transmit_subscription_rejection.action_cable instrumentations

This means we can safely “intercept” any of those messages and produce a log whenever it has finished processing. How do we do that? As an addition to “regular” event subscriptions, Rails also provides a special ActiveSupport::LogSubscriber interface designed to consume notifications and generate logs as the only output. For demonstration purposes, let's subscribe to perform_action.action_cable. Let's define a separate initializer, e.g. my_action_cable_log_subscriber.rb:

class MyActionCableLogSubscriber < ActiveSupport::LogSubscriber
  def perform_action(event)
    info "[Action Cable] #{event.payload[:channel_class]} - #{event.payload[:action]} (Duration: #{event.duration})"
  end
end

MyActionCableLogSubscriber.attach_to :action_cable

As you can see, we had to create a class inheriting from ActiveSupport::LogSubscriber. In it we'd have to define a method named exactly as the instrumentation name, in this example: perform_action. This method accepts a single event argument which is an ActiveSupport::Notifications::event object containing data defined in instrumentation itself and some additional calculated metrics (e.g. duration). Finally, we can generate an info log - the method delegates to the ActiveSupport logger (Rails.logger by default). Feel free to experiment with it, e.g. by creating an error log in case of an exception:

class MyActionCableLogSubscriber < ActiveSupport::LogSubscriber
  def perform_action(event)
    base_log = "#{event.payload[:channel_class]} - #{event.payload[:action]}"

    exception = event.payload[:exception_object]
    if exception
      error "[Action Cable - Failure] #{base_log} (Error: #{exception.message})"
    else
      info "[Action Cable] #{base_log} (Duration: #{event.duration})"
    end
  end
end

MyActionCableLogSubscriber.attach_to :action_cable

This will produce following logs:

[Action Cable] MyChannel - my_method (Duration: 5.57)
...
[Action Cable - Failure] MyChannel - my_method (Error: Invalid)

Similarly, we could add other methods such as broadcast or transmit, but keep in mind that they need to match the instrumentation name. Then, all we need to do is to register our subscriber to action_cable scope by calling attach_to. Pretty simple, eh?

Unfortunately, not everything is instrumented: we’re still lacking instrumentations in open, close, subscribed and unsubscribed actions. Fixing this requires (again) monkey patching or fixing this once and for all in Action Cable source code.

Happy coding with Action Cable!