Cutting test and import wait times in a Godot project

The whole test suite went from 36 min 29 s to 22 min 51 s on the same checkout. A Godot import now skips itself in under a second when nothing it reads has changed, and the check that builds a model twice and compares the bytes only runs when the model is installed. It’s partly done, because the list of things to cut is longer than these three.

Where was the time going?

I’d spent a lot of time waiting for tests and rebuilds, so I wanted to know where the bottlenecks were before cutting anything. I counted every shell call in three days of agent transcripts, timed from the call to its result. That came to 66.6 hours of shell time, and 56.5 of those were the agents working in the background.

• Model builds in Blender were about 28 hours, or 42%. The step that builds everything twice was 6.1 hours of that.
• Test suites were about 14.7 hours, or 22%.
• Godot imports were 5.2 hours, or 8%. There were 235 of them, with a mean of 80 seconds.
• Films and screenshots were about 5 hours, or 8%.

So the suite was the second biggest cost and not the first. I picked three cuts to start with, which were the import, the slow end of the suite and the build-twice step.

Skipping an import that has nothing to do

My first idea was a cache of results. But what actually costs time is asking the engine to import when it has nothing to do, so a small Python script now decides whether anything changed without starting Godot.

The script keeps a stamp in the checkout’s .godot folder, which is never in git. The stamp covers every file Godot’s scan of res:// would see, minus the kinds an import makes nothing from, like text, Python, shell and the JSON the game reads itself. For each file it keeps the size, the modified time and a hash of what an import takes from it. A file whose size and time match isn’t opened. A file whose time moved gets hashed, and if the hash matches, the stamp just takes the new time. That covers switching a branch and switching back, or saving a file without changing it.

A GDScript outside addons/ only counts by its top-level class_name, extends, @tool, @icon, @abstract and @static_unload lines, plus whether the file and its .uid exist. Those are what Godot keeps in its global class cache. The game compiles a script body from text on every run, so editing a body needs no import. A script under addons/ runs inside the importing editor, so the whole file counts.

The stamp also records which Godot did the import and that the import’s products still exist. If there’s any doubt, it imports. That means no stamp, a stamp it can’t read, a failed import, or a file that changed while Godot was importing. A test with 49 checks covers those cases, and a --force flag imports no matter what the stamp says.

A warm import went from 7.8 s to 0.7 s, and the warm load check that imports first went from 18.2 s to 11.2 s. A cold import with no .godot folder takes 134 s either way. So that 80 second mean was mostly real work or a busy machine, and this saves about 7 seconds from each import that wasn’t needed.

Why did 14 tests take longer than the other 136?

The suite ran 136 of its 150 tests eight at a time in about 12.5 minutes. Then it ran the other 14 one at a time for 16 minutes. Those 14 were the tests that start a Godot editor and the tests that measure frame time.

The editor tests waited until the end because two editors can’t be open on one project folder. I tried giving each test its own Godot home folder first, and it didn’t help. On Windows an editor loads a copy of each GDExtension library, and for the terrain addon that copy is a file inside the project’s addons/terrain_3d/bin folder. The first editor holds that file open, so the second editor fails with “Error copying library” and gets no terrain. The file is in the project and not in Godot’s home, so a separate home doesn’t fix it. A game running next to an editor is fine, because the game loads the library directly.

So the editor tests still run one at a time, but they do it in a separate lane while the other tests are running, and not after them.

One test, dungeon_shapes, ran alone only because two of its checks are timed. I split those two into a small test called dungeon_cost, which takes 8 seconds alone, and the rest of it runs with the others now.

The two long frame tests fly a route through the world and watch frame times. Headless, they now fly the same route at 27 m/s and not 9. They cross the same borders and build and free the same things, and I didn’t change any limit. One went from 143 s to 53 s and the other from 209 s to 75 s.

The slow end of the suite went from 17 min 39 s to 6 min 12 s.

Building a model twice only when it’s installed

Step 12 of the model pipeline builds a model a second time and checks that the bytes match. The agents were running it by hand on every iteration, and running it again on old models to prove a change to the shared kit hadn’t altered them.

Now the install command makes the second build when the model’s record has no passing step 12 for those bytes. Every installed model still passes the step. I proved it on a hall piece installed into a scratch folder. The missing step was made and passed in 8 seconds, a model that already had it took 0.2 seconds, and a second build I made differ was refused.

For the kit question there’s a new command that makes one build and compares it byte for byte with what’s installed. Both are wired into four of the model families so far, which are meat, props, interiors and machines.

What’s still slow, and what’s still failing?

One frame test still fails, and the test is right. When a dungeon that was freed gets built again as the party comes back, one call in the world streamer takes 432 to 568 ms in a single frame, and the limit is 400. The rock of the dungeon is only 19 to 36 ms of that. The rest is the furniture, machines, interiors and meat that go in it. In play that’s a hitch of about half a second the first time the party gets near a dungeon. I’m going to spread that build over several frames, and the limit stays at 400 until then.

With the slow end cut, the eight-at-a-time part is 16.5 of the 22.9 minutes, and it’s limited by its longest tests and not by how many there are. The three longest take 363 to 426 seconds each. Those are on the list, along with reusing a suite result when the same tree was already tested. The other model families don’t have the install-time second build yet.