DEV Community: Clément Morisset

How to optimize factory creation.

Clément Morisset — Wed, 21 Dec 2022 20:24:45 +0000

At Potloc we have a test stack which is pretty standard in the Rails ecosystem. We run tests with RSpec, we use FactoryBot for setting up our test data, Capybara for user interactions, Github Actions as a CI etc..

These great tools allow us to code at a fast pace with good test coverage. But this pace comes at a cost. The more the team grows, the bigger the codebase gets and the more tests get written.

🤕 The issue

As developer we usually take care of optimizing our own code and queries, we are used to test new implementations with all the edge cases. But tests optimization is likely a topic that we put at the bottom of the list and that’s if we ever even think about it.
Up until the moment where quietly but surely you will end up with a CI that take ages to run and a whole test suite to speed up.

Let’s see how we took on this challenge at Potloc.

For the purpose of demonstration we will rely on this simple test file:

RSpec.describe Purging::QuestionnaireWorker, type: :worker do
  let(:questionnaire) { create(:questionnaire) }

  describe "#perform" do
    it "destroys a survey form" do
      expect { subject.perform(questionnaire.id) }.to change(Questionnaire, :count).by(-1)
    end

    context "given associations" do
      it "destroys a questionnaire and its associations" do
        create(:question, :postal_code, questionnaire: questionnaire)

        expect { subject.perform(questionnaire.id) }.to change(SurveyQuestion, :count).by(-1)
      end
    end
  end
end

🧑‍🚒 The solutions

The factory-bot gem is used in almost in all of our spec files and it make our set up much more easier than when we use fixtures.
Here is the tradeoff, the easier the gem is to use, the more likely you’ll end up with some pain to control its usage. And when the times come to tackle slow tests, the best bet you can take is to start digging into you factories because it’s likely they are the primary reason why your test suite is slowing down

Avoiding the factory cascades

To quote Evil Martian a factory cascade is an

uncontrollable process of generating excess data through nested factory invocations.

In our test we use two factories a questionnaire and question who could be represented like this as a tree:

questionnaire
|
|---- survey

question
|
|---- survey

In this simple example each factory calls a nested factory. This means that every time we create a questionnaire factory, we also create a survey factory.

To have a better vision of what objects are created in our spec file we can use test-prof, a powerful gem that provides a collection of different tools to analyse your test suite performance. One of this tool is really useful to identify a factory cascade, let’s introduce factory profiler.

If we run FPROF=1 bundle exec rspec the factory profiler, it will generate the following report:

[TEST PROF INFO] Factories usage

 Total: 6
 Total top-level: 3
 Total time: 00:01.005 (out of 00:26.087)
 Total uniq factories: 3

   total   top-level     total time      time per call      top-level time               name

       3           0        0.6911s            0.2304s             0.0000s             survey
       2           2        0.6397s            0.3199s             0.6397s             questionnaire
       1           1        0.3658s            0.3658s             0.3658s             question

The most interesting insight is the difference between the total and the top-level. The more this difference is important, the more you end up with factory cascade, meaning that you are creating useless factories.

Let’s take the survey , we don’t instantiate any surveys in our test suite but during the execution we create 4.

The easiest workaround it is to instantiate a survey at the top-level and to associate the factories to it.

RSpec.describe Purging::QuestionnaireWorker, type: :worker do
  let(:survey) { create(:survey) }
  let(:questionnaire) { create(:questionnaire, survey: survey) }
  ....

  it "destroys a questionnaire and its associations" do
    create(:question, :postal_code, questionnaire: questionnaire, survey: survey)
    ....

If we run the factory profiler we now have a different report:

[TEST PROF INFO] Factories usage

 Total: 5
 Total top-level: 5
 Total time: 00:00.868 (out of 01:09.067)
 Total uniq factories: 3

   total   top-level     total time      time per call      top-level time               name

       2           2        0.6986s            0.3493s             0.6986s             survey
       2           2        0.0973s            0.0487s             0.0973s             questionnaire
       1           1        0.0729s            0.0729s             0.0729s             question

Nice! No more factory cascades. The total and the top-level columns are the same. We now create 5 factories instead of 8. We have decreased the time spent creating factories by 30%.

The caveat of this method it that it could be a heavy process to maintain. Thankfully, test-prof as a recipe called FactoryDefault. Removing factory cascades manually could be good enough most of the time but if you want to go further you can follow the documentation.

That being said, test-prof has even more to offer, it’s time to introduce an awesome helper named let_it_be.

Reuse the factory you need

Let's bring a little bit of magic and introduce a new way to set up a shared test data.

let_it_be is a helper that allows you to reuse the same factory for all your spec file. In our example we don’t need to create 2 survey and 2 questionnaire we could re-use the same ones for all our file.

RSpec.describe Purging::QuestionnaireWorker, type: :worker do
  let_it_be(:survey) { create(:survey) }
  let_it_be(:questionnaire) { create(:questionnaire, survey: survey) }
  ...
end

If we run the factory profiler we now have a different report:

[TEST PROF INFO] Factories usage

 Total: 3
 Total top-level: 3
 Total time: 00:00.272 (out of 00:24.264)
 Total uniq factories: 3

   total   top-level     total time      time per call      top-level time               name

       1           1        0.2024s            0.2024s             0.2024s             survey
       1           1        0.0323s            0.0323s             0.0323s             questionnaire
       1           1        0.0375s            0.0375s             0.0375s             question

So now we only create the factories we need, by reusing the same ones throughout our file.

Be aware that let_it_be come with a caveat section. I strongly encourage you to read the documentation and use this powerful helper in accordance with your needs.

🚀 Conclusion

Let’s take a step back and relish our improvements:

	Initial	Without cascades	With let_it_be
Factories creation time	00:01.00	00:00.868	00:00.272

Numbers look nice for this simple example. But what is the impact in real life at Potloc?

So far we just applied this recipe for a specific folder of our codebase. Below the result by profiling locally that folder:

Before we spent 3.50 min in factories creation, now 2 min. (~ -50%)
Before we created 6824 factories, now 4378. (~ -35%)

test-prof is the swiss army knife we needed to speed up our test suite. It’s still a long journey but by embracing this topic we have already taken an important step!

Want to go further? Watch this 99 problems of slow test talk by Vladimir Dementyev

Interested in what we do at Potloc? Come join us! We are hiring 🚀

Streamline a service desk with JIRA automation

Clément Morisset — Mon, 17 Jan 2022 12:22:38 +0000

At Potloc our service desk is dedicated for the operation teams where they can open a ticket for a bug or a service request. The more our web application grows, the more maintenance it requires. As a result we’ve seen a growing number of tickets pertaining to the same project.

The need

We wanted a way to link these tickets together to gather additional context.

Were there any issues on this project in the past?
What was the solution?
Which developer worked on it?

These questions can be crucial in getting the visibility required when it comes to debugging.

The solution

One word: Automation

This aptly named feature allows you to automate tasks through a series of actions triggered by specific events.

Let’s link all created tickets for the same project using automation.

The how

In our particular case the event is When a new issue is created . The entry point for grouping tickets by a specific project is the url field. Each request has a link to easily locate the issue. In 99% of case our url will have the ID of a project. So the first action that you need to process after the creation of an issue is to scan the URL in order to extract the project ID.

1. Extract the survey ID

You can have a hidden field that is not displayed to the user but will allow you to store the extracted ID.
Let's add a New component > New action > Edit an issue and the field you want to use. For the purpose of this article we will use Root cause.

Above we are using Smart values, according to Jira documentation:

Smart values allow you to access issue data within Jira. For example, you can use the following smart values to send a Slack message that includes the issue key and issue summary: {{issue.key}} {{issue.summary}}

customfield_10364: is the ID for our URL field that contains the project ID. You can go to settings or inspect your input to find it.

substringBetween: is a built-in function that returns the text between the given parameters.

From this moment your field will contain the ID. But to have an up to date flow (with the extracted ID) we have to refetch the data issue by adding a new action Re-fetch data issue.

Next, we would like to link issues with the same project ID.

2. Find linked issues

Jira has an action for this called Lookup issues.

cf[10359] : is the identifier of our Root cause field (replace the number with your ID)

issue.customfield_10359 : is the identifier of the Root cause field for the other issues

issueKey != "issue.key" : we exclude our current issue of the lookup

⚠️ Careful! Your fields will be named differently according to your need.

What we do, in pseudo code, is basically searching via JQL if the extracted ID of the issue matches any previously-created issues. We also ensure we exclude the current issue of the search.

Note: In our context, Root cause is a text field. It's likely that you have to find another operator if the type of your field is different.

3. Link similar issues

Finally, we need to link all results from our previous query with our current issue using the Link issue to action.

That's it. From now on you should see previously-created tickets for this project on all your tickets.

Here’s the final result:

Pro tips: You could add a condition as a guard clause to stop the automation if the Lookup issues actions does not return anything.

Happy automation. 🎉

Interested in what we do at Potloc? Come join us! We are hiring 🚀

How to use Sentry for profiling a test suite

Clément Morisset — Mon, 20 Sep 2021 20:11:37 +0000

At Potloc one of our core values is learning, that's why each quarter the development team has a dedicated time to explore new things. This aptly named Dev Happiness Week allows us to tackle either a new pattern, open source project, write a blog post and so on.

One of my initial projects was to monitor our test suite. The more our test suite was growing quickly the more seconds were added to our CI. But without any monitoring on how long each test takes to run it was complicated to identify and speed up the slowest ones. Let's fix this by asking the following question:

What is the minimal valuable move to have a test profiling dashboard ?

We use Sentry for error tracking and they have a great feature for performance monitoring that allow you to track queries and get transactions duration.

Hence the following steps will show you how to twist the performance overview page of Sentry into a test suite monitoring. 🤓

Disclaimers: The following example assume that you use RSpec gem and that you already have a dedicated Sentry environment for it (eg: app-test-suite).

We would like to satisfy three specifications:

Cover all of our test suite
Don't flood our monitoring with unnecessary data (eg: unit tests that run in under 1 second)
Make it easy to locate our slower tests

Cover all of our test suite

The easy one. Let's start by creating a profiling.rb file that will be run in our test suite, add an around hook and compute the elapsed time between the beginning of a run and the end.

#spec/support/config/profiling.rb

RSpec.configure do |config|
  config.around(:example) do |example|
    example_start = Time.now

    example.run

    example_end = Time.now
    elapsed_time_in_seconds = example_end - example_start
  end
end

Nice, we now cover the first bullet point of our specification.

Don't flood our monitoring with unnecessary data

The purpose here is to avoiding flooding Sentry when everything work as expected. We just want to send data when a test is slow or takes longer than expected.

We don't have the same expectations between a system test and a unit test. Hence we have to set a different thresholds accordingly:

#spec/support/config/profiling.rb

SLOW_EXECUTION = ["system"].freeze
MEDIUM_EXECUTION = ["integration", "export"].freeze
SLOW_EXECUTION_THRESHOLD = 6
MEDIUM_EXECUTION_THRESHOLD = 3
DEFAULT_EXECUTION_THRESHOLD = 1

RSpec.configure do |config|
  config.around(:example) do |example|
    category = spec_category(example)
    example_start = Time.now

    example.run

    example_end = Time.now
    elapsed_time_in_seconds = example_end - example_start
    if execution_time_in_seconds > threshold_for(category)
      print "Slow alert!"
    end
  end
end

# input: "./spec/integration/restaurants/owner_spec.rb:16"
# output: "integration"
def spec_category(example)
  location = example.metadata[:location].to_s
  location.gsub("./spec/", "")
          .scan(%r{^[^/]*})[0]
end

def threshold_for(category)
  case category
  when *SLOW_EXECUTION then SLOW_EXECUTION_THRESHOLD
  when *MEDIUM_EXECUTION then MEDIUM_EXECUTION_THRESHOLD
  else
    DEFAULT_EXECUTION_THRESHOLD
  end
end

Firstly we set our threshold constants, corresponding maximum execution times.
Then we add a spec_category method that allows us to identify the type of test, and we check if the runtime is lower or higher than expected.
If it does we print a beautiful message.

We are almost there! We just have to generate a custom Sentry transaction in order to populate the performance table with our profiling data.

#spec/support/config/profiling.rb

...

RSpec.configure do |config|
  config.around(:example) do |example|
    category = spec_category(example)
    example_start = Time.now
    transaction = Sentry::Transaction.new(op: category.upcase, hub: Sentry.get_current_hub)

    example.run

    ...

    if execution_time_in_seconds > threshold_for(category)       
      transaction.finish
    end

    ...

Our Sentry::Transaction takes 2 arguments:

op : used for the name of the operation (eg: sql.query ). In our case we will populate it with the category of our spec.
hub: Sentry requires an hub, we use the current. According to documentation "You can think of the hub as the central point that our SDKs use to route an event to Sentry"

By finishing our transaction we send our event to Sentry. From now on you should see your first tests appear on the performance dashboard.

Feel free to read Sentry documentation for a better understanding the performance table.

⚠️ By tweaking the performance dashboard of Sentry for our test suite we have to deal with the expected behaviour of Sentry. Such as send event when there is fail in your environnement

That's why it's necessary to add the following configuration in our Sentry test initializer.

#spec/support/config/sentry.rb

Sentry.init do |config|
  config.dsn = "https://4**************************************3"
  config.excluded_exceptions += ["Exception"]
end

In our context of profiling we won't send an event when a test fails on our CI. For avoiding noise and flooding you have to exclude all exceptions.

Make it easy to locate our slower tests

By default the transaction name corresponds to the name of the controller where the transaction has been run. In the screenshot above it shows that our test uses the method template in ChartsController. It's not really convenient to identify what test this concerns.
We need to tweak our transaction a little bit more:

#spec/support/config/profiling.rb

...

RSpec.configure do |config|
  config.around(:example) do |example|
    ...

    if execution_time_in_seconds > threshold_for(category) 
      assign_custom_transaction_name(example)
      transaction.finish
    end
  end
end

...

def assign_custom_transaction_name(example)
  Sentry.configure_scope do |scope|
    scope.set_transaction_name(example.metadata[:location])
  end
end

By using the configuration scope we are able to update our transaction name. According to documentation, "The scope will hold useful information that should be sent along with the event".

Here we assign our test path as the transaction name. That's it.
Run your test again and you should see

For the purpose of development we didn't add a guard clause so far, but you can check if you are on your CI environment before profiling your tests.

The entire profiling.rb class should look like this.

#spec/support/config/profiling.rb

SLOW_EXECUTION = ["system"].freeze
MEDIUM_EXECUTION = ["integration", "export"].freeze
SLOW_EXECUTION_THRESHOLD = 6
MEDIUM_EXECUTION_THRESHOLD = 3
DEFAULT_EXECUTION_THRESHOLD = 1

RSpec.configure do |config|
  if ENV["CI"]
    config.around(:example) do |example|
      category = spec_category(example)
      example_start = Time.now

      example.run

      example_end = Time.now
      elapsed_time_in_seconds = example_end - example_start

      if execution_time_in_seconds > threshold_for(category)         
        assign_custom_transaction_name(example)
        transaction.finish
      end
    end
  end
end

# input: "./spec/integration/restaurants/owner_spec.rb:16"
# output: "integration"
def spec_category(example)
  location = example.metadata[:location].to_s
  location.gsub("./spec/", "")
          .scan(%r{^[^/]*})[0]
end

def threshold_for(category)
  case category
  when *SLOW_EXECUTION then SLOW_EXECUTION_THRESHOLD
  when *MEDIUM_EXECUTION then MEDIUM_EXECUTION_THRESHOLD
  else
    DEFAULT_EXECUTION_THRESHOLD
  end
end

def assign_custom_transaction_name(example)
  Sentry.configure_scope do |scope|
    scope.set_transaction_name(example.metadata[:location])
  end
end

That's all, happy profiling ! 🎉

Interested in what we do at Potloc? Come join us! We are hiring 🚀