"No timing found for" the same few test files on every new branch

Every build on a new branch is missing timings data for the same few files, so all our first runs for new feature branches are slow :cry:

We see “No timing found” for several files, the same every time on new branch builds. And when I SSH onto the machine (before the store_test_results job has uploaded on the new branch) and look in it’s circleci-test-results/results.json file, those test files are indeed missing.

However, subsequent builds on the same branch (even rerunning the same commit) have all the timings data :thinking: These runs are much quicker! And every build on the default branch is quick too, no missing timings there, presumably because the branch has always existed.

So, the store_test_results job is definitely uploading all the tests timings correctly, and CircleCI is splitting by those timings correctly. But on new branches, the timings data it mounts onto the job machines is never complete :cry:

How can I fix this please?

Is there a cache that’s used for builds on new branches?

How come circleci-test-results/results.json is so different in the first run on a new branch?

Thanks in advance!
Henry

Steps to replicate

Step 5 shows the bug.

Summary

Setup:

Have a default branch configured in CircleCI.

Have some tests that have been run to completion in CircleCI before, and their timings uploaded via the store_test_results job.

Look at the test results timings of the last default branch test job, via curl CircleCI API Reference - it should include all the test files.

Now to replicate:

  1. create a new branch off the default one
  2. push it to the remote repository (github) to trigger CircleCI
  3. wait until the test job starts, then cancel the workflow, and choose Rerun > Rerun job with SSH on the test job
  4. when SSH becomes available on any of the parallel nodes, SSH onto one of them
  5. look at the test results timings mounted onto the machine: file=$(find /tmp/ -type f -name 'results.json'); jq '.tests[].file' $file | sort | uniq - it will be missing some files
  6. exit SSH and allow the workflow to complete - “No timing found” is printed in each parallel test step, for each file missing from the results timings file
  7. look at the test results timings of the test job run via curl CircleCI API Reference - it will include all the test files
  8. choose Rerun > Rerun job with SSH again
  9. when SSH becomes available on the second workflow on any of the parallel nodes, SSH onto one of them
  10. look at the test results timings mounted onto the machine: file=$(find /tmp/ -type f -name 'results.json'); jq '.tests[].file' $file | sort | uniq - it will include all the test files
  11. exit SSH and allow the workflow to complete - “No timing found” is not printed in any of the parallel reruns

Full config

Summary
version: 2.1

orbs:
  browser-tools: circleci/browser-tools@1

jobs:
  build: &base
    docker:
      - image: cimg/ruby:3.3.1-browsers
    shell: /bin/bash --login
    steps:
      - checkout
      - run: 'bundle install' # et al
      - save_cache:
          key: ruby330-gemfile-{{ .Branch }}-{{ checksum "Gemfile.lock" }}
          paths:
            - ~/.bundle

  test:
    <<: *base
    resource_class: medium
    parallelism: 4
    steps:
      - checkout
      - restore_cache:
          keys:
            - ruby330-gemfile-{{ .Branch }}-{{ checksum "Gemfile.lock" }}
      - run:
          command: |
            circleci tests glob "spec/**/*_spec.rb" | \
            circleci tests run --verbose --split-by=timings --command="\
              xargs bundle exec rspec --force-color --require spec_helper \
              --format progress \
              --format RspecJunitFormatter -o tmp/rspec/rspec_timings.xml \
            "
      - store_test_results:
          path: tmp/rspec
          when: always

Weirdly, the incomplete timings data has more test cases than the complete timings data after a workflow finishes :thinking:

It has 52 test files, vs 71 in the complete data: jq '.tests[].file' | sort | uniq | wc -l
But it has 733 test cases, vs 671 in the complete data: jq '.tests|length'

Example incomplete timings filepath: /tmp/.circleci-task-data-612871c5-3304-4e53-ae7a-ff2b5c8fab62-0-build/circle-test-results/results.json

Example complete timings filepath: /tmp/.circleci-task-data-389b168f-73b2-4782-a8d0-819f55be45bb-0-build/circle-test-results/results.json

Is there anything in the filename that I can use to try to figure out where it’s coming from?

Ah sorry, figured it out! I forgot that we were applying a method in Rerun failed tests - CircleCI to ensure Rerun > Rerun failed tests can still report complete timings data

plus we had two workflows running at the same time on the same commit, and were saving to the same cache key, so that’s why test results were all mixed up when being uploaded =)

This can be closed now =)