Guo Xiang

I built RubyBench.org

I had my first encounter of a real world race condition today while fixing a bug for Discourse. For some reason, users were not getting a notification when an automated moderator post is added to the topic. After tracing through the source code, I found the method that was responsible for adding the automated post:

def add_moderator_post(user, text, opts=nil)
  opts ||= {}  
  new_post = nil
  Topic.transaction do
    creator = PostCreator.new(user,
                              raw: text,
                              post_type: opts[:post_type] || Post.types[:moderator_action],
                              action_code: opts[:action_code],
                              no_bump: opts[:bump].blank?,
                              skip_notifications: opts[:skip_notifications],
                              topic_id: self.id,
                              skip_validations: true)
    new_post = creator.create
    increment!(:moderator_posts_count)
  end

  # ...
end

We can see that Discourse uses a PostCreator class to handle the logic of creating a new post and that was being done in Topic.transaction. After creating the post, a counter for the number of moderator posts is increased by one. The next step was to look at PostCreator#create and find out what is happening in there:

  def create
    if valid?
      transaction do
        # ...
        save_post
        # ...
      end
    end

    if @post && errors.blank?
      # ... 
      enqueue_jobs
      # ...
    end

    # ...

    @post
  end

We can see that enqueue_jobs is called only after the post has been saved within the transaction. Within the job, the execute method takes in the post_id and retrieves the post from the database.

module Jobs
  class PostAlert < Jobs::Base

    def execute(args)
      # maybe it was removed by the time we are making the post
      if post = Post.find_by(id: args[:post_id])
        # maybe the topic was deleted, so skip in that case as well
        PostAlerter.post_created(post) if post.topic
      end
    end

  end
end

First thing I did was to check if the job was even executed at all. Checking Sidekiq's logs, I didn't notice any failing jobs so that wasn't too helpful. Since the job is being called, that means the condition in the job was not evaluating to true. To confirm my suspicion, I threw in a puts statement:

def execute(args)
  puts Post.find(args[:post_id])

  # maybe it was removed by the time we are making the post
  if post = Post.find_by(id: args[:post_id])
    # maybe the topic was deleted, so skip in that case as well
    PostAlerter.post_created(post) if post.topic
  end
end

Boom! ActiveRecord::RecordNotFound: Couldn't find Post with 'id'=752 [WHERE ("posts"."deleted_at" IS NULL)]. I didn't understand what was happening. The record should have been saved and the Sidekiq job should be able to query for it. I made a wild guess and thought it was a timing issue (I was totally wrong on this) and decided to throw in a sleep(10):

def execute(args)
  sleep(10)
  puts Post.find(args[:post_id])

  # maybe it was removed by the time we are making the post
  if post = Post.find_by(id: args[:post_id])
    # maybe the topic was deleted, so skip in that case as well
    PostAlerter.post_created(post) if post.topic
  end
end

It finally worked but I still didn't know the root cause. However, I did make an adjustment by changing Post.find_by to Post.find. The difference is that Post.find_by returns nil if it doesn't find any record which means the job is silently ignored. With Post.find, an exception would have been raised and Sidekiq would retry the job at a later time.

After tracing through the code a couple more times, I finally noticed that we had two transactions going on with one being nested in the other. The code was essentially something like this:

def add_moderator_post(user, text, opts=nil)
  # ...
  Topic.transaction do
    creator = PostCreator.new(user,
                              raw: text,
                              post_type: opts[:post_type] || Post.types[:moderator_action],
                              action_code: opts[:action_code],
                              no_bump: opts[:bump].blank?,
                              skip_notifications: opts[:skip_notifications],
                              topic_id: self.id,
                              skip_validations: true)

    # Called by creator.create
    if valid?
      transaction do
        # ...
        save_post
        # ...
      end
    end

    if @post && errors.blank?
      # ... 
      enqueue_jobs
      # ...
    end

    increment!(:moderator_posts_count)
  end

  # ...
end

After realizing that we were enqueuing a job within a transaction, it finally all made sense. In order for a record to be persisted in the database, it has to be committed. In the case of having nested transactions, the newly created post was not committed into the database until Topic.transaction was done and we were enqueuing the job before Topic.transaction had finished whatever it had to within its block. Since is Sidekiq is so fast, it was able to execute the job even before the code within Topic.transaction has completed which explains why the post record could not be fetched. After understanding what was happening, the fix was pretty straight forward:

-    Topic.transaction do
-      creator = PostCreator.new(user,
-                                raw: text,
-                                post_type: opts[:post_type] || Post.types[:moderator_action],
-                                action_code: opts[:action_code],
-                                no_bump: opts[:bump].blank?,
-                                skip_notifications: opts[:skip_notifications],
-                                topic_id: self.id,
-                                skip_validations: true)
-      new_post = creator.create
-      increment!(:moderator_posts_count)
-    end
+    creator = PostCreator.new(user,
+                              raw: text,
+                              post_type: opts[:post_type] || Post.types[:moderator_action],
+                              action_code: opts[:action_code],
+                              no_bump: opts[:bump].blank?,
+                              skip_notifications: opts[:skip_notifications],
+                              topic_id: self.id,
+                              skip_validations: true)
+    new_post = creator.create
+    increment!(:moderator_posts_count) if new_post.persisted?

I hope you learned something today as I have and feel free to ask me any questions in the comments below :)


Recently, Peter Wilmott presented his benchmark results of Ruby compiled with different versions and optimization levels of GCC and Clang. However, the benchmarks were ran on an Amazon EC2 instance where CPU allocation may not be consistent while running the whole benchmark suite. Therefore, I suspected that the benchmarks might have been somewhat inaccurate and instead ran all benchmarks on a Softlayer Bare Metal Server:

System Type Component
Operating System Ubuntu14.04-64 Minimal for Bare Metal
RAM 4x4GB Kingston 4GB DDR3 1Rx8
Processor 3GHz Intel Xeon-IvyBridge (E5-2690-V2-DecaCore)
Motherboard SuperMicro X9DRI-LN4F+_R1.2A
Power Supply SuperMicro PWS-605P-1H

With references to Peter's work, I re-implemented the scripts with the following limitations imposed:

  • Ruby 2.2.0 compiled from Ruby's 2_2 branch.

  • No CFLAGS were set which defaults optimization to "-O3" since this is what most people will have installed.

  • Instead of running https://github.com/acangiano/ruby-benchmark-suite, I ran the benchmark suite available in Ruby's repository.

  • Repeat count for Ruby's benchmark suite was set to 5.

Unlike what Peter did, I chose not to collate the data using the points system as small differences will be unfairly amplified. Instead, I followed Peter's updated version where percentage deviation from the baseline for each benchmark type is presented. The percentage deviation is calculated by taking the current value and dividing it by the average value for all the compilers.

Percentage faster/slower (Lower is better)

The graph is best viewed by only comparing two compilers at a time.

See the Pen Highcharts.js with Google Spreadsheets by Guo Xiang Tan (@tgxworld) on CodePen.

These are the things I noticed:
* Benchmark results for each compiler type is pretty similar if you compare the shape of the graphs.

  • Performance do deviate between Clang and GCC but that could also be noise. Certain benchmark types deviate alot more (vm_ensure, vm_mutex1).

  • Ruby compiled with GCC 4.6 performs better overall.

  • ¯\(ツ)/¯ I can't reach a decent conclusion about the overall performance. Feel free to let me know how you might interpret the data in the comments below.

As I couldn't reach a conclusion with Ruby's benchmarks, I decided to dig deeper and run the compiled Rubies against Discourse's benchmark script.

Discourse Benchmarks (Lower is better)

Update: I included all percentiles as I realized that the 50th percentile is pretty stable even across different Ruby releases

See the Pen Highcharts.js with Google Spreadsheets by Guo Xiang Tan (@tgxworld) on CodePen.

As you can see from the graph above, your Rails application is probably not going to be affected too much by the compiler that was used to compile Ruby. While the compiler used might not matter, the version of Ruby that you're using matters. If you're interested in the long term performance of Ruby, head over to RubyBench.org and find out how each Ruby release is performing.

To replicate the scripts, follow the instructions on my GitHub respository.

Thoughts, comments, mistakes? Let me know below :)


While working on RubyBench, I was trying to execute the following Docker commands through Net::SSH in Ruby:

docker run --name discourse_redis -d redis:latest &&
docker run --name discourse_postgres -d postgres:latest &&
docker run --rm --link discourse_postgres:postgres --link discourse_redis:redis -e \"RAILS_COMMIT_HASH=#{commit_hash}\"  tgxworld/discourse_rails_head_bench"
# Dockerfile

FROM tgxworld/ruby:0.1
MAINTAINER Guo Xiang "tgx_world@hotmail.com"

# ...

CMD /bin/bash -l -c "./runner && cd discourse && ruby script/bench.rb -m -n"
# !/bin/bash
set -e

cd /
createdb -T template0 -h "$POSTGRES_PORT_5432_TCP_ADDR" -p "$POSTGRES_PORT_5432_TCP_PORT" -U postgres discourse_profile
pg_restore --no-owner -h "$POSTGRES_PORT_5432_TCP_ADDR" -p "$POSTGRES_PORT_5432_TCP_PORT" -U postgres -d discourse_profile 

This resulted in the following error when trying to create a new DB in PostgreSQL:

createdb: could not connect to database template1: could not connect to server: Connection refused
    Is the server running on host "172.17.2.206" and accepting
    TCP/IP connections on port 5432?

So the question I asked was "Why isn't the connection available even though I've already linked the containers?" To make matters worst, I couldn't replicate the error when running the commands manually. After Googling for what seems like hours to me, I finally found the issue "Is there a way to delay container startup to support dependant services with a longer startup time" which explained why the connection to PostgreSQL was failing. Running Docker commands through Net::SSH, instead of manually by hand, executed the script which creates the database even before the PostgreSQL server has been established in the detached PostgreSQL container. In order to ensure that the script only runs after the PostgreSQL connection has been established, we can ping the port and only executes the script once the connection has been established.

# !/bin/bash
set -e

# See https://github.com/dominionenterprises/tol-api-php/blob/master/tests/provisioning/set-env.sh
while ! exec 6<>/dev/tcp/${POSTGRES_PORT_5432_TCP_ADDR}/${POSTGRES_PORT_5432_TCP_PORT}; do
  echo "$(date) - still trying to connect to Postgres server"
  sleep 1
done

cd /
createdb -T template0 -h "$POSTGRES_PORT_5432_TCP_ADDR" -p "$POSTGRES_PORT_5432_TCP_PORT" -U postgres discourse_profile
pg_restore --no-owner -h "$POSTGRES_PORT_5432_TCP_ADDR" -p "$POSTGRES_PORT_5432_TCP_PORT" -U postgres -d discourse_profile 

Hopefully this helps!



This post summarizes the first ever Ruby talk I gave at a RubySG meetup

*Follow the instructions here to install Overcommit before reading the tutorial*

Despite Overcommit being an opinionated git hook manager, it is fully configurable and extendable as well. In this tutorial, I will walk you through on how you can write a pre-commit hook (with tests) that enforces a maximum length for each line in your files through the use of the APIs provided by the Overcommit gem.

Step 1. Putting the files in the right directory

By default, Overcommit looks for your custom hooks in the .git-hooks folder which we can configure by overriding plugin_directory in your .overcommit.yml settings file. For pre-commit hooks, you'll want to put all your hooks under the following directory:

# <your_app>/.git-hooks/pre_commit/line_length.rb

Step 2. Write your custom hook

# <your_app>/.git_hooks/pre_commit/line_length.rb

module Overcommit::Hook::PreCommit
  class LineLength < Base
    # Overcommit expects you to override this method which will be called
    # everytime your pre-commit hook is run.
    def run
      # Create two arrays to hold our error and warning messages.
      error_lines = []
      warning_lines = []

      # The `config` attribute is a hash of
      # your settings based on your `.overcommit.yml` file.
      max_line_length = config['max']

      # For pre-commit hooks, `applicable_files` is one of the methods that
      # Overcommit provides which returns an array of files that have been
      # modified for the particular commit.
      applicable_files.each do |file|
        # `modified_lines` is another method provided by Overcommit. It will
        # return an array containing the index of lines in the file which have
        # been modified for the particular commit.
        modified_lines_num = modified_lines(file)

        # Loop through each file with the index.
        File.open(file, 'r').each_with_index do |line, index|
          # Check if the length of line is greater than our desired length.
          if line.length > max_line_length
            message = format("#{file}:#{index + 1}: Line is too long [%d/%d]",
              line.length, max_line_length)

            # If the line is included in our modified lines, we will add it to
            # `error_lines`, else add it to `warning_lines`.
            if modified_lines_num.include?(index + 1)
              error_lines << message
            else
              warning_lines << message
            end
          end
        end
      end

      # Overcommit expects 1 of the 3 as return values, `:fail`, `:warn` or `:pass`.
      # If the hook returns `:fail`, the commit will be aborted with our message
      # containing the errors.
      return :fail, error_lines.join("\n") if error_lines.any?

      # If the hook returns `:warn`, the commit will continue with our message
      # containing the warnings.
      return :warn, "Modified files have lints (on lines you didn't modify)\n" <<
        warning_lines.join("\n") if warning_lines.any?

      :pass
    end
  end
end

Step 3. Enable and configure your pre-commit hook in the settings file

PreCommit:
  LineLength:
    enabled: true  # All custom hooks are disabled by default.
    description: Checking for length of lines  # Prints a description when your hook is run.
    max: 89  # Setting the max length to 89 chars. Accessed through the `config` attribute in our hook.
    excludes: 
      - '**/*.rb'  # Rubocop is already checking for the length of lines in Ruby.
      - '**/*.gif' # However, we are interested in ensuring that the line of lines
      - '**/*.jpg' # in our HAML and YAML files follow the same rules as well.
      - '**/*.png'

Step 4. Writing tests for your pre-commit hook

# spec/overcommit/pre_commit/line_length_spec.rb

require 'spec_helper'
require 'overcommit'
require 'overcommit/hook/pre_commit/base'
require Rails.root.join('.git-hooks/pre_commit/line_length')

describe Overcommit::Hook::PreCommit::LineLength do
  let(:config) do
    # Load our settings file and initialize an instance of `Overcommit::Configuration`.
    Overcommit::Configuration.new(YAML.load_file('.overcommit.yml'))
  end

  # The context which the hook is running in. For pre-commit hooks, it will be
  # an instance of `Overcommit::HookContext::Precommit`. However, we would not be
  # needing this in our tests so we will just create a double for it.
  let(:context) { double('context') }

  # Path to our fixture.
  let(:staged_file) { '<your_app>/spec/overcommit/fixtures/test_file.txt' }

  # Create an instance of our hook passing in our configuration and context.
  subject! { described_class.new(config, context) }

  before do
    # Stub `applicable_files` to return our fixture.
    allow(subject).to receive(:applicable_files).and_return([staged_file])
  end

  context 'when file contains line which are too long' do
    context 'when all the lines have been modified' do
      before do
        # Stub `modified_lines` to return the scenario where all 3 lines have been
        # modified.
        allow(subject).to receive(:modified_lines).and_return([1, 2, 3])
      end

      it 'should return the right status and error message' do
        expect(subject.run).to eq(
          [
            :fail,
            "#{staged_file}:1: Line is too long [99/89]\n" <<
            "#{staged_file}:3: Line is too long [99/89]"
          ]
        )
      end
    end

    context 'when only the second line has been modified' do
      # Assert that `subject.run` to return `:warn` with our warning lines.
    end
  end

  context 'when file do not contain line which are too long' do
    # Assert that `subject.run` to return `:pass`
  end
end
# spec/overcommit/fixtures/test_file.txt

This line is purposely written so that it will be more than 89 characters and fail pre_commit hook
This line is short
This line is purposely written so that it will be more than 89 characters and fail pre_commit hook

That is all in writing a custom Overcommit pre-commit hook. If you're interested to learn more about the API that Overcommit provides, I urge you to look into Overcommit's library of hooks to see how other hooks are implemented.


Google