Jonathan's Movies Discover Bug

Spotting bugs is easy but fixing them can often be a challenge. Here’s the story of how I lost three hours of sleep last night to an unlikely bug.

A couple of years ago I built a web app to help people vote on and choose a film to watch at my usual Sunday film night at my friend Jonathan’s house. The initial version was rough but the concept was a success, and it’s endured as perhaps my most successful hobby project!

For a while now there’s been a subtle bug that’s persisted which thrust into the spotlight this Sunday ¹ - it irked me so much that I stayed up until the small hours of the morning tracking it down and fixing it. The bug appears on the Discover Page, where a user can infinitely scroll through a semi-randomly selection of movies which should appear only once ². Sometimes however, a film would reappear in the selection - very near its original appearance. Whilst this isn’t a game changing bug it did make for some odd scenarios.

Understanding the Discover Process

The main component of the Discover Page is the randomly generated, infinitely scrolling list of ‘Popular and Highly Rated’ movies. This list is generated by separating the movies owned by Jonathan into four categories. “Tier one” movies, “tier two” movies, “tier three” movies, and movies that plain don’t make the cut. The tiers (or buckets!) are determined by evaluating the film’s Rotten Tomatoes rating, IMDB rating, and popularity on TMDB - which is fetched on a weekly basis. The most popular and most highly rated movies are put into the first tier, and so on. The tiers are exclusive, a film cannot appear in the first tier and then the third tier for instance.

When a user opens up the Discover Page and starts scrolling it sends a request to the server to request twelve movies to display. When a response is received the movies are added to an array of suggested movies and are displayed on the page. The unique identifiers of the movies already received are also stored.

As the user scrolls towards the end of the page another request is triggered, but this time the request is sent with the ids of the movies that have already been seen so that the server can avoid sending the same movies again and thus avoid the case where a user would ‘discover’ the same film twice.

Tracking Down the Bug

The logic seems fairly sound - so where was the bug coming from? The first clue was in when the duplicates appeared. Duplicates were frequently seen towards the end of the infinite scroll, and tended to cluster elsewhere. It seemed likely that you were more likely to observe a duplicate either when crossing the boundaries of a tier (you’d already seen nearly all the “tier one” films and the response needed to contain some tier one films and some tier two films) or when a tier only had a few unseen movies left. This line of investigation would suggest the bug was in the server’s handling of which movies to send back - so I added a couple of lines of code to the function that handled receiving the response to check if duplicates were indeed being sent.

// Requests movies from the server.
const discoveredFilms = await discoverMovies(this.seenIds)

// Adds the new movies to the array of movies we're displaying on the page.
this.suggestions = this.suggestions.concat(discoveredFilms)

// For each 'new' movie, check whether the film's id exists in the array
// of movie ids we've previously received. If so, log an error message.
for (let film of discoveredFilms) {
  if (this.seenIds.indexOf(film._id) !== -1) {
    console.error(`Seen duplicate of ${film.name}`)
  }
  // Add the movie to the array of movie ids we've seen.
  this.seenIds.push(film._id)
}

Sure enough, the console had about half a dozen cases where a duplicate movie had crept in. This confirmed my suspicions that the problem was on the server.

The server side had fairly complicated code for handling discover. When the server booted up, and again once a week, it would ‘calculate’ the movies that belong in each tier - that logic seemed pretty sound. The more complicated logic was the logic that sent twelve unique movies back to the user - but I couldn’t find any culprits there either, the server was definitely avoiding responding with any movie that matched a ‘seen’ id that it had received.

// Calculate which bucket to initially 'draw' movies from.
const seenIds = new Set(params.query._id.$nin);
const totalSeen = seenIds.size;
const buckets = service.discoveredFilms;
const correctBucket = totalSeen < buckets.tierOneFilmCount ? 'tierOneFilms' : totalSeen >= (buckets.tierTwoFilmCount + buckets.tierOneFilmCount) ? 'tierThreeFilms' : 'tierTwoFilms';

// The pool of movies that the user hasn't seen for the current tier.
const discoverPool = difference(buckets[correctBucket], seenIds);

// We need to randomly select from the buckets to prevent sending everyone the same films in the same order.
const chunkSize = 12;
let chosenFilms = randomlySelectAmount(discoverPool, chunkSize);

// If the remaining size of the first discover pool isn't large enough for a full chunk
// then select the remaining films from the next bucket
if (chosenFilms.length < chunkSize && correctBucket !== 'tierThreeFilms') {
    const newSeen = totalSeen + chosenFilms.length;
    const newBucket = newSeen < buckets.tierOneFilmCount ? 'tierOneFilms' : newSeen > buckets.tierTwoFilmCount ? 'tierThreeFilms' : 'tierTwoFilms';
    const secondDiscoverPool = difference(buckets[newBucket], union(seenIds, new Set(chosenFilms)));
    const extraChosenFilms = randomlySelectAmount(secondDiscoverPool, chunkSize - chosenFilms.length);
    chosenFilms = chosenFilms.concat(extraChosenFilms);
}

Race Conditions

If the server and client both seemed to have sound logic for handling which movies the user had already seen it seemed likely the bug was a form of race condition, a type of bug where the behaviour of the program depends on the correct sequencing of events. Although both halves of the process were technically correct they only worked under the right conditions. My hunch was that it was possible for multiple requests to be made in parallel, sent with the same set of ‘seen movies’, and then the user might receive the same film twice (or more times) across the responses to those requests.

Fixing such a bug was a little tricky but not too complicated. First I needed to create a queuing system which would enforce mutual exclusion of the request sending and processing logic - in other words it should be impossible for more than one request to be sent to the server at a time.

To do this I create a ‘queue’ which tracks the number of requests that are expected to be sent. The request function marks itself asbusy, when a request is being processed so during that case then the fact another request should be sent is marked by incrementing the queueCount.

// The scroll listener calls this function
refreshQueueWrapper () {
      if (this.busy) {
        this.queueCount++
      } else {
        this.refresh()
      }
}

Finally, I made some adjustments to the refresh function to ensure that if there are pending requests that it automatically fetches again.

refresh: async function () {

  this.busy = true
  try {
    const discoveredFilms = await discoverMovies(this.seenIds)
    this.suggestions = this.suggestions.concat(discoveredFilms)
    this.seenIds = this.seenIds.concat(discoveredFilms.map(f => f._id))
  } catch (e) {
    // Removed for the sake of brevity
  } finally {
    this.busy = false
    // If another fetch has been queued up, mark it as being done and then fetch movies again.
    if (this.queueCount > 0) {
      this.queueCount--
      this.refresh()
    }
  }
}

After, all requests became strictly sequential duplicate movies stopped appearing! Now we know why the duplicates appeared originally, we can explain why duplicates tended to cluster together.

As the user sees more movies by scrolling through the Discover Page the number of possible movies that can be sent to the user decreases, until the start of a new tier begins. As the pool becomes depleted, two back to back requests are more likely to randomly select the same movies to appear. This likelihood then dramatically reduces at the start of a tier causing three points in the Discover Page where duplicates cluster: the end of tier one, the end of tier two, and the end of infinite scrolling.