28.7. How is SCons Making Its Decisions? the --taskmastertrace Option

The internal SCons subsystem that handles walking the dependency graph and controls the decision-making about what to rebuild is the Taskmaster. SCons supports a --taskmastertrace option that tells the Taskmaster to print information about the children (dependencies) of the various Nodes on its walk down the graph, which specific dependent Nodes are being evaluated, and in what order.

The --taskmastertrace option takes as an argument the name of a file in which to put the trace output, with - (a single hyphen) indicating that the trace messages should be printed to the standard output:

env = Environment(CPPPATH = ['.'])
env.Program('prog.c')
      
% scons -Q --taskmastertrace=- prog
Job.NewParallel._work(): [Thread:8682049344] Gained exclusive access
Job.NewParallel._work(): [Thread:8682049344] Starting search
Job.NewParallel._work(): [Thread:8682049344] Found 0 completed tasks to process
Job.NewParallel._work(): [Thread:8682049344] Searching for new tasks

Taskmaster: Looking for a node to evaluate
Taskmaster:     Considering node <no_state   0   'prog'> and its children:
Taskmaster:        <no_state   0   'prog.o'>
Taskmaster:      adjusted ref count: <pending    1   'prog'>, child 'prog.o'
Taskmaster:     Considering node <no_state   0   'prog.o'> and its children:
Taskmaster:        <no_state   0   'prog.c'>
Taskmaster:        <no_state   0   'inc.h'>
Taskmaster:      adjusted ref count: <pending    1   'prog.o'>, child 'prog.c'
Taskmaster:      adjusted ref count: <pending    2   'prog.o'>, child 'inc.h'
Taskmaster:     Considering node <no_state   0   'prog.c'> and its children:
Taskmaster: Evaluating <pending    0   'prog.c'>

Task.make_ready_current(): node <pending    0   'prog.c'>
Task.prepare():      node <up_to_date 0   'prog.c'>
Job.NewParallel._work(): [Thread:8682049344] Found internal task
Task.executed_with_callbacks(): node <up_to_date 0   'prog.c'>
Task.postprocess():  node <up_to_date 0   'prog.c'>
Task.postprocess():  removing <up_to_date 0   'prog.c'>
Task.postprocess():  adjusted parent ref count <pending    1   'prog.o'>
Job.NewParallel._work(): [Thread:8682049344] Searching for new tasks

Taskmaster: Looking for a node to evaluate
Taskmaster:     Considering node <no_state   0   'inc.h'> and its children:
Taskmaster: Evaluating <pending    0   'inc.h'>

Task.make_ready_current(): node <pending    0   'inc.h'>
Task.prepare():      node <up_to_date 0   'inc.h'>
Job.NewParallel._work(): [Thread:8682049344] Found internal task
Task.executed_with_callbacks(): node <up_to_date 0   'inc.h'>
Task.postprocess():  node <up_to_date 0   'inc.h'>
Task.postprocess():  removing <up_to_date 0   'inc.h'>
Task.postprocess():  adjusted parent ref count <pending    0   'prog.o'>
Job.NewParallel._work(): [Thread:8682049344] Searching for new tasks

Taskmaster: Looking for a node to evaluate
Taskmaster:     Considering node <pending    0   'prog.o'> and its children:
Taskmaster:        <up_to_date 0   'prog.c'>
Taskmaster:        <up_to_date 0   'inc.h'>
Taskmaster: Evaluating <pending    0   'prog.o'>

Task.make_ready_current(): node <pending    0   'prog.o'>
Task.prepare():      node <executing  0   'prog.o'>
Job.NewParallel._work(): [Thread:8682049344] Found task requiring execution
Job.NewParallel._work(): [Thread:8682049344] Executing task
Task.execute():      node <executing  0   'prog.o'>
cc -o prog.o -c -I. prog.c
Job.NewParallel._work(): [Thread:8682049344] Enqueueing executed task results
Job.NewParallel._work(): [Thread:8682049344] Gained exclusive access
Job.NewParallel._work(): [Thread:8682049344] Starting search
Job.NewParallel._work(): [Thread:8682049344] Found 1 completed tasks to process
Task.executed_with_callbacks(): node <executing  0   'prog.o'>
Task.postprocess():  node <executed   0   'prog.o'>
Task.postprocess():  removing <executed   0   'prog.o'>
Task.postprocess():  adjusted parent ref count <pending    0   'prog'>
Job.NewParallel._work(): [Thread:8682049344] Searching for new tasks

Taskmaster: Looking for a node to evaluate
Taskmaster:     Considering node <pending    0   'prog'> and its children:
Taskmaster:        <executed   0   'prog.o'>
Taskmaster: Evaluating <pending    0   'prog'>

Task.make_ready_current(): node <pending    0   'prog'>
Task.prepare():      node <executing  0   'prog'>
Job.NewParallel._work(): [Thread:8682049344] Found task requiring execution
Job.NewParallel._work(): [Thread:8682049344] Executing task
Task.execute():      node <executing  0   'prog'>
cc -o prog prog.o
Job.NewParallel._work(): [Thread:8682049344] Enqueueing executed task results
Job.NewParallel._work(): [Thread:8682049344] Gained exclusive access
Job.NewParallel._work(): [Thread:8682049344] Starting search
Job.NewParallel._work(): [Thread:8682049344] Found 1 completed tasks to process
Task.executed_with_callbacks(): node <executing  0   'prog'>
Task.postprocess():  node <executed   0   'prog'>
Job.NewParallel._work(): [Thread:8682049344] Searching for new tasks

Taskmaster: Looking for a node to evaluate
Taskmaster: No candidate anymore.
Job.NewParallel._work(): [Thread:8682049344] Found no task requiring execution, and have no jobs: marking complete
Job.NewParallel._work(): [Thread:8682049344] Gained exclusive access
Job.NewParallel._work(): [Thread:8682049344] Completion detected, breaking from main loop

The --taskmastertrace option doesn't provide information about the actual calculations involved in deciding if a file is up-to-date, but it does show all of the dependencies it knows about for each Node, and the order in which those dependencies are evaluated. This can be useful as an alternate way to determine whether or not your SCons configuration, or the implicit dependency scan, has actually identified all the correct dependencies you want it to.