Fix Superfluous Task Dependency

There is actually a massive bug in our implementation. If you noticed the issue while following this tutorial, you’re pretty observant! If you didn’t catch it, don’t worry. I actually didn’t catch it either up until this point!

I decided to keep the bug in to show how hard it is to test incrementality and soundness.

Let’s start by adding another testing task which we need to uncover the bug, and then write a test that manifests the bug.

Add ToUpper task

Modify pie/src/tests/common/mod.rs to add another task:

The ToUpper task does (as expected) the opposite of the ToLower task: it requires the string providing task and returns the string in uppercase.

Test case setup

No we set up a test case uncover the bug. Modify pie/src/tests/top_down.rs to add another test:

This test is similar to the previous one, but we have added a ToUpper task which requires the ToLower task. We first require ToLower and assert that only ToLower and ReadFile are executed. ToUpper should not be executed because we have not required it, and neither ToLower nor ReadFile require it.

Then, we require ToUpper and assert that it is executed. Neither ToLower nor ReadFile should be executed because their dependencies are still consistent.

Check that this test, so far, succeeds with cargo test. You can inspect the build log with cargo test --test top_down test_no_superfluous_task_dependencies to see what is going on, but it should look pretty normal. The important part of this setup is that ToLower returns "hello, world!".

Manifest the bug

Manifest the bug by modifying pie/src/tests/top_down.rs:

We change file in a very specific way: we capitalize the l characters to L characters. We do this to trigger early cutoff. By changing file in this way, we expect ReadFile to execute and return "HeLLo, WorLd!". This in turn means that ToLower’s task dependency to ReadFile is inconsistent, because the output changed, so ToLower is executed. However, ToLower changes those L characters back into l and returns "hello, world!", which is the same as last time. Therefore, ToUpper’s task dependency to ToLower is still consistent, and we can cut off the build early. We assert this inside the require_then_assert block.

But, if you run the tests with cargo test, this test will fail! How can that be?

Inspect the build log with cargo test --test top_down test_no_superfluous_task_dependencies. The third (last) build log should look like this:

→ ToUpper(ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)))
 ? ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
  → ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
   ✗ /tmp/.tmpzsuOJk/in.txt (old: Modified(Some(SystemTime { tv_sec: 1703256545, tv_nsec: 289192956 })) ≠ new: Modified(Some(SystemTime { tv_sec: 1703256545, tv_nsec: 293192959 })))
   ▶ ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
    - /tmp/.tmpzsuOJk/in.txt
   ◀ Ok(String("HeLLo, WorLd!"))
  ← Ok(String("HeLLo, WorLd!"))
 ✗ ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified) (old: Equals(Ok(String("Hello, World!"))) ≠ new: Equals(Ok(String("HeLLo, WorLd!"))))
 ▶ ToUpper(ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)))
  → ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified))
   ? ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
    → ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
    ← Ok(String("HeLLo, WorLd!"))
   ✗ ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified) (old: Equals(Ok(String("Hello, World!"))) ≠ new: Equals(Ok(String("HeLLo, WorLd!"))))
   ▶ ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified))
    → ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
    ← Ok(String("HeLLo, WorLd!"))
   ◀ Ok(String("hello, world!"))
  ← Ok(String("hello, world!"))
 ◀ Ok(String("HELLO, WORLD!"))
← Ok(String("HELLO, WORLD!"))

In this last build, ToUpper is required, and it will check its dependency to ReadFile. But that shouldn’t happen, because ToUpper only has a dependency to ToLower! There seems to be a bug where ToLower’s task dependency to ReadFile, somehow ended up with ToUpper.

We need to go back to our consistency checking code to find the cause.

Finding the cause

In the previous chapter, we implemented dynamic dependencies including an is_inconsistent method to check if a dependency is consistent. This is the code we used for task dependencies:

  pub fn is_inconsistent<C: Context<T>>(&self, context: &mut C) -> Option<OutputStamp<T::Output>> {
    let output = context.require_task(&self.task);
    let new_stamp = self.stamper.stamp(output);
    if new_stamp == self.stamp {
      None
    } else {
      Some(new_stamp)
    }
  }

To check if a task dependency is consistent, we call require on the context (which calls require_task_with_stamper with a default stamper). Later on we implemented this require_task_with_stamper method for TopDownContext:

    self.session.tracker.require_task_start(task, &stamper);
    let node = self.session.store.get_or_create_task_node(task);

    // Get required task output by executing it if needed, or by getting the output from the store if not needed.
    let already_consistent = self.session.consistent.contains(&node);
    let should_execute = !already_consistent && self.should_execute_task(&node);
    let output = if should_execute {
      self.session.tracker.execute_start(task);
      self.session.store.reset_task(&node);
      let previous_executing_task = self.session.current_executing_task.replace(node);
      let output = task.execute(self);
      self.session.current_executing_task = previous_executing_task;
      self.session.store.set_task_output(&node, output.clone());
      self.session.tracker.execute_end(task, &output);
      output
    } else {
      // Correctness: when `should_execute_task` returns `true`, the above block is executed. Otherwise this block is
      // executed and `should_execute_task` ensures that the task has an output.
      self.session.store.get_task_output(&node).clone()
    };

    let dependency = TaskDependency::new(task.clone(), stamper, output.clone());
    self.session.tracker.require_task_end(&dependency, &output, should_execute);

    // Create task require dependency if a task is currently executing (i.e., we are not requiring the initial task).
    if let Some(current_executing_task_node) = &self.session.current_executing_task {
      if self.session.store.add_task_require_dependency(current_executing_task_node, &node, dependency).is_err() {
        let current_executing_task = self.session.store.get_task(current_executing_task_node);
        panic!("Cyclic task dependency; current executing task '{:?}' is requiring task '{:?}' which was already required", current_executing_task, task);
      }
    }

    self.session.consistent.insert(node);
    output
  }
}

In the if let Some(current_executing_task_node) block we are adding a task dependency from the current executing task (if any), to the task being required. This is the cause of the bug. Even if we are only consistency checking a task to see if it should be executed, we could end up adding a task dependency to the current executing task, which is not correct. We only manifested the bug in the last test due to having a chain of 2 task dependencies, and by carefully controlling what is being executed and what is being checked.

Recall the second build in the test_no_superfluous_task_dependencies test. The build log for that build looks like:

→ ToUpper(ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)))
 ▶ ToUpper(ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)))
  → ToLower(ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified))
   ? ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
    → ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
     ✓ /tmp/.tmpzsuOJk/in.txt
    ← Ok(String("Hello, World!"))
   ✓ ReadFile("/tmp/.tmpzsuOJk/in.txt", Modified)
  ← Ok(String("hello, world!"))
 ◀ Ok(String("HELLO, WORLD!"))
← Ok(String("HELLO, WORLD!"))

In this build we are executing ToUpper, then require ToLower, then consistency check ReadFile, which in turn requires ReadFile. At the end of that require, an incorrect dependency from ToUpper to ReadFile is made (although not really visible in the log). This incorrect dependency then later breaks incrementality.

To fix this bug, we need to make sure that we only add task dependencies when an executing task directly requires another task, not when consistency checking!

Fixing the bug

To fix the bug, we will separate the process of making a task consistent, which does not add task dependencies, from requiring a task, which can add task dependencies. We will split this part into a make_task_consistent method. Modify the top-down context from pie/src/context/top_down.rs:

We extracted the core of the require_task_with_stamper method into a make_task_consistent method, and call make_task_consistent in require_task_with_stamper. This is a refactoring, so the require_task_with_stamper method will behave the same as before.

To reiterate, make_task_consistent makes given task is consistent by checking the task, executing it if inconsistent, and returning its output. If it is already consistent, we return the cached output. In both cases we also use and update self.session.consistent: the set of already consistent tasks this session.

Now we need to change the is_inconsistent methods on dependencies to use make_task_consistent instead. However, the is_inconsistent method is generic over Context, which doesn’t expose the make_task_consistent method. We also do not want to expose make_task_consistent to users of the library, as it would allow tasks authors to make tasks consistent without adding dependencies, which could break incrementality. Therefore, we will define a MakeConsistent trait in the dependency module, and have TopDownContext implement that.

Modify pie/src/dependency.rs:

We add the MakeConsistent trait and use it in is_inconsistent. Now we go back to TopDownContext and implement that trait.

Modify pie/src/context/top_down.rs:

We implement the MakeConsistent trait on TopDownContext, forwarding it to the make_task_consistent method.

We also need to implement this trait for the NonIncrementalContext. Modify pie/src/context/non_incremental.rs:

If you run cargo test now, test_no_superfluous_task_dependencies should succeed, indicating that we fixed the bug! However, test_require_task now fails 😅.

An assert!(execute.start() > require.start()) in this test now fails, which is a sanity check asserting that “executes starts” should be later than “require starts” This is because our changes have correctly removed several superfluous task requires, which influences these assertions.

Inspect the build log for this test with cargo test --test top_down test_require_task. The second build now looks like:

→ ToLower(ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified))
 ? ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified)
  ✓ /tmp/.tmpngoUZ4/in.txt
 ✓ ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified)
← Ok(String("hello world!"))

In this second build, ReadFile is now no longer required, and instead is only checked. This is correct, and does not make any assertions fail.

The third build now looks like:

→ ToLower(ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified))
 ? ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified)
  ✗ /tmp/.tmpngoUZ4/in.txt (old: Modified(Some(SystemTime { tv_sec: 1703256546, tv_nsec: 177193271 })) ≠ new: Modified(Some(SystemTime { tv_sec: 1703256546, tv_nsec: 181193272 })))
  ▶ ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified)
   - /tmp/.tmpngoUZ4/in.txt
  ◀ Ok(String("!DLROW OLLEH"))
 ✗ ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified) (old: Equals(Ok(String("HELLO WORLD!"))) ≠ new: Equals(Ok(String("!DLROW OLLEH"))))
 ▶ ToLower(ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified))
  → ReadFile("/tmp/.tmpngoUZ4/in.txt", Modified)
  ← Ok(String("!DLROW OLLEH"))
 ◀ Ok(String("!dlrow olleh"))
← Ok(String("!dlrow olleh"))

In this third build, ReadFile is also no longer required at the start, but later on in the build it is required when ToLower is executed. This is correct, as it is only checked (using make_task_consistent) at the start, but required later while ToLower is executing.

The problem is that this assertion just does not hold anymore, as a task can be executed without first being required. What does hold, is that a task is only executed after being checked or required. However, we don’t track checking in the event tracker, so we will just remove this assertion to keep the tutorial going. We will also update the expected build logs in the comments to reflect our changes.

Fix the tests by modifying pie/src/tests/top_down.rs:

Confirm this fixes the tests with cargo test. All tests are green! 🎉🎉🎉