Yet another random failing spec

(Everyday Code – instead of keeping our knowledge in a README.md let’s share it with the internet)

This article is about a random failing spec. I spent more than 5 hours on this trying to track it down so I decided to share with our team what has happened and what the stupid mistake was.

Random failing

Random failing specs are most of the time passing and sometimes failing. The context of their fail seems to be random.

Context

At FLLCasts.com we have categories. There was an error when people were visiting the categories. We receive each and every error on an email and some of the categories stopped working, because of a wrong sql query. After migration from Rails 6.0 to Rails 6.1 some of the queries started working differently mostly because of eager loads and we had to change them.

The spec

This is the code of the spec

 scenario "show category content" do
    category = FactoryBot.create(:category, slug: SecureRandom.hex(16))
    episode = FactoryBot.create(:episode, :published_with_thumbnail, title: SecureRandom.hex(16))
    material = FactoryBot.create(:material, :published_with_thumbnail, title: SecureRandom.hex(16))
    program = FactoryBot.create(:program, :published_with_thumbnail, title: SecureRandom.hex(16))
    course = FactoryBot.create(:course, :published_with_thumbnail, title: SecureRandom.hex(16))

    category.category_content_refs << FactoryBot.create(:category_content_ref, content: episode, category: category)
    category.category_content_refs << FactoryBot.create(:category_content_ref, content: material, category: category)
    category.category_content_refs << FactoryBot.create(:category_content_ref, content: program, category: category)
    category.category_content_refs << FactoryBot.create(:category_content_ref, content: course, category: category)

    expect(category.category_content_refs.count).to eq 4
    visit "/categories/#{category.to_param}"

    find_by_xpath_with_page_dump "//a[@href='/tutorials/#{episode.to_param}']"
    find_by_xpath_with_page_dump "//a[@href='/materials/#{material.to_param}']"
    find_by_xpath_with_page_dump "//a[@href='/programs/#{program.to_param}']"
    find_by_xpath_with_page_dump "//a[@href='/courses/#{course.to_param}']"

  end

We add a few objects tot he category and then we check that we see them when we visit the category.

The problem

Sometime while running the spec only 1 of the objects in the category are shown. Sometimes non, most of the time all of them are shown.

The debug process

The controller

def show
  @category_content_refs ||= @category.category_content_refs.published
end

In the category we just call published to get all the published content that is in this category. There are other things in the show but they are not relevant. We were using apply_scopes, we were using other concerns.

The model

  scope :published, lambda {
    include_contents.where(PUBLISHED_OR_COMING_WHERE_SQL)
  }

The scope in the model makes a query for published or coming.

And the query, i kid you not, that was committed in 2018 and we’ve had this query for so long was

class CategoryContentRef < ApplicationRecord
   
    PUBLISHED_OR_COMING_WHERE_SQL = ' (category_content_refs.content_type = \'Episode\' AND (episodes.published_at <= ? OR episodes.is_visible = true) ) OR
     (category_content_refs.content_type = \'Course\' AND courses.published_at <= ?) OR
     (category_content_refs.content_type = \'Material\' AND (materials.published_at <= ? OR materials.is_visible = true) ) OR
     category_content_refs.content_type=\'Playlist\'', *[Time.now.utc.strftime("%Y-%m-%d %H:%M:%S")]*4].freeze

end

I will give you a hit that the problem is with this query.

You can take a moment a try to see where the problem is.

The query problem

The problem is with the .freeze and the constant in the class. The query is initialized when the class is loaded. Because of this it takes the time at the moment of loading the class and not the time of the query.

Because the specs are fast sometimes the time of loading of the class is right before the spec and sometimes there are specs executed in between.

It seems simple once you see it, but these are the kind of things that you keep missing while debugging. They are right in-front of your eyes and yet again sometimes you just can’t see them, until you finally see them and they you can not unsee them.