(Under development, subject to change)
This tutorial showcases the features of TensorFlow Debugger (tfdbg) command-line interface. It contains an example of how to debug a frequently encountered problem in TensorFlow model development: bad numerical values (nan
s and inf
s) causing training to fail.
To observe such an issue, run the following code without the debugger:
bazel build -c opt tensorflow/python/debug:debug_mnist && \
bazel-bin/tensorflow/python/debug/debug_mnist
This code trains a simple NN for MNIST digit image recognition. Notice that the accuracy increases slightly after the first training step, but then gets stuck at a low (near-chance) level:
Accuracy at step 0: 0.1113
Accuracy at step 1: 0.3183
Accuracy at step 2: 0.098
Accuracy at step 3: 0.098
Accuracy at step 4: 0.098
Accuracy at step 5: 0.098
Accuracy at step 6: 0.098
Accuracy at step 7: 0.098
Accuracy at step 8: 0.098
Accuracy at step 9: 0.098
Scratching your head, you suspect that certain nodes in the training graph generated bad numeric values such as inf
s and nan
s. The computation-graph paradigm of TensorFlow makes it hard to debug such model internal states with general-purpose debuggers such as Python's pdb. tfdbg specializes in diagnosing these types of issues and pinpointing the exact node where the problem first surfaced.
To add support for tfdbg in our example, we just need to add the following three lines of code, which wrap the Session object with a debugger wrapper when the --debug
flag is provided:
if FLAGS.debug:
sess = tf_debug.LocalCLIDebugWrapperSession(sess)
sess.add_tensor_filter("has_inf_or_nan", tf_debug.has_inf_or_nan)
This wrapper has the same interface as Session, so enabling debugging requires no other changes to the code. But the wrapper provides additional features including:
run()
call, to let you control the execution and inspect the graph's internal state.In this example, we are registering a tensor filter called "has_nan_or_inf"
, which simply determines if there are any nan
or inf
values in any intermediate tensor of the graph. (This filter is a common enough use case that we ship it with the debug_data
module.)
def has_inf_or_nan(datum, tensor): return np.any(np.isnan(tensor)) or np.any(np.isinf(tensor))
TIP: You can also write your own custom filters. See tensorflow/python/debug/debug_data.py
for additional filter examples.
Let's try training the model again with debugging enabled. Execute the command from above, this time with the --debug
flag added:
bazel build -c opt tensorflow/python/debug:debug_mnist && \
bazel-bin/tensorflow/python/debug/debug_mnist --debug
The debug wrapper session will prompt you when it is about to execute the first run()
call, with information regarding the fetched tensor and feed dictionaries displayed on the screen.
--- run-start: run #1: fetch: accuracy/accuracy/Mean:0; 2 feeds
======================================
About to enter Session run() call #1:
Fetch(es):
accuracy/accuracy/Mean:0
Feed dict(s):
input/x-input:0
input/y-input:0
======================================
Select one of the following commands to proceed ---->
run:
Execute the run() call with the debug tensor-watching
run -n:
Execute the run() call without the debug tensor-watching
run -f <filter_name>:
Keep executing run() calls until a dumped tensor passes
a given, registered filter emerge. Registered filter(s):
* has_inf_or_nan
--- Scroll: 0.00% ----------------------------------------------
tfdbg>
This is what we refer to as the run-start UI. If the screen size is too small to display the content of the message in its entirety, you can use the PageUp / PageDown / Home / End keys to navigate the screen output.
As the screen output indicates, the first run()
call calculates the accuracy using a test data set—i.e., a forward pass on the graph. You can enter the command run
to launch the run()
call. This will bring up another screen right after the run()
call has ended, which will display all dumped intermedate tensors from the run. (These tensors can also be obtained by running the command lt
after you executed run
.) This is called the run-end UI:
--- run-end: run #1: fetch: accuracy/accuracy/Mean:0; 2 feeds --
21 dumped tensor(s):
[0.000 ms] accuracy/correct_prediction/ArgMax/dimension:0
[0.000 ms] softmax/biases/Variable:0
[0.013 ms] hidden/biases/Variable:0
[0.112 ms] softmax/weights/Variable:0
[1.953 ms] hidden/weights/Variable:0
[4.566 ms] accuracy/accuracy/Const:0
[5.188 ms] accuracy/correct_prediction/ArgMax_1:0
[6.901 ms] hidden/biases/Variable/read:0
[9.140 ms] softmax/biases/Variable/read:0
[11.145 ms] softmax/weights/Variable/read:0
[19.563 ms] hidden/weights/Variable/read:0
[171.189 ms] hidden/Wx_plus_b/MatMul:0
[209.433 ms] hidden/Wx_plus_b/add:0
[245.143 ms] hidden/Relu:0
--- Scroll: 0.00% ----------------------------------------------
tfdbg>
Try the following commands at the tfdbg>
prompt (referencing the code at third_party/tensorflow/python/debug/examples/debug_mnist.py
):
Print the value of the tensor hidden/Relu:0.
In this first run()
call, there happen to be no problematic numerical values. You can exit the run-end UI by entering the command exit
. Then you will be at the second run-start UI:
--- run-start: run #2: fetch: train/Adam; 2 feeds --------------
======================================
About to enter Session run() call #2:
Fetch(es):
train/Adam
Feed dict(s):
input/x-input:0
input/y-input:0
======================================
...
Instead of entering run
repeatedly and manually searching for nan
s and inf
s in the run-end UI after every run()
call, you can use the following command to let the debugger repeatedly execute run()
calls without stopping at the run-start or run-end prompt, until the first nan
or inf
value shows up in the graph:
tfdbg> run -f has_inf_or_nan
NOTE: This works because we have previously registered a filter for nan
s and inf
s called has_inf_or_nan
(as explained previously). If you have registered any other filters, you can let tfdbg run till any tensors pass that filter as well, e.g.,
# In python code:
sess.add_tensor_filter('my_filter', my_filter_callable)
# Run at tfdbg run-start prompt:tfdbg> run -f my_filter
After you enter run -f has_inf_or_nan
, you will see the following screen with a red-colored title line indicating tfdbg stopped immediately after a run()
call generated intermediate tensors that passed the specified filter has_inf_or_nan
:
--- run-end: run #4: fetch: train/Adam; 2 feeds ----------------30 dumped tensor(s) passing filter "has_inf_or_nan":[13.255 ms] cross_entropy/Log:0
[13.499 ms] cross_entropy/mul:0
[14.426 ms] train/gradients/cross_entropy/mul_grad/mul:0
[14.681 ms] train/gradients/cross_entropy/mul_grad/Sum:0
[14.885 ms] train/gradients/cross_entropy/Log_grad/Inv:0
[15.239 ms] train/gradients/cross_entropy/Log_grad/mul:0
[15.378 ms] train/gradients/softmax/Softmax_grad/mul:0
--- Scroll: 0.00% ----------------------------------------------
tfdbg>
As the screen display indicates, the has_inf_or_nan
filter is first passed during the fourth run()
call: an Adam optimizer forward-backward training pass on the graph. In this run, 30 (out of the total 87) intermediate tensors contain nan
or inf
values. These tensors are listed in chronological order, with their timestamps displayed on the left. At the top of the list, you can see the first tensor in which the bad numerical values first surfaced: cross_entropy/Log:0
.
To view the value of the tensor, run
tfdbg> pt cross_entropy/Log:0
Scroll down a little and you will notice some scattered inf
values. If the instances of inf
and nan
are difficult to spot by eye, you can use the following command to perform a regex search and highlight the output:
tfdbg> /inf
Or, alternatively:
tfdbg> /(inf|nan)
To go back to the list of "offending" tensors, use the up-arrow key to navigate to the following command, and hit Enter:
tfdbg> lt -f has_inf_or_nan
To further debug, display more information about cross_entropy/Log
:
tfdbg> ni cross_entropy/Log
--- run-end: run #4: fetch: train/Adam; 2 feeds ---
Node cross_entropy/Log
Op: Log
Device: /job:localhost/replica:0/task:0/cpu:0
1 input(s) + 0 control input(s):
1 input(s):
[Softmax] softmax/Softmax
3 recipient(s) + 0 control recipient(s):
3 recipient(s):
[Mul] cross_entropy/mul
[Shape] train/gradients/cross_entropy/mul_grad/Shape_1
[Mul] train/gradients/cross_entropy/mul_grad/mul
You can see that this node has the op type Log
and that its input is the node softmax/Softmax
. Run the following command to take a closer look at the input tensor:
tfdbg> pt softmax/Softmax:0
Examine the values in the input tensor, and search to see if there are any zeros:
tfdbg> /0\.000
Indeed, there are zeros. Now it is clear that the origin of the bad numerical values is the node cross_entropy/Log
taking logs of zeros. You can go back to the source code in debug_mnist.py
and infer that the culprit line is:
diff = y_ * tf.log(y)
Apply a value clipping on the input to tf.log
to resolve this problem:
diff = y_ * tf.log(tf.clip_by_value(y, 1e-8, 1.0))
Now, try training again with --debug
:
bazel build -c opt tensorflow/python/debug:debug_mnist && \
bazel-bin/tensorflow/python/debug/debug_mnist --debug
Enter run -f has_inf_or_nan
at the tfdbg>
prompt and confirm that no tensors are flagged as containing nan
or inf
values, and accuracy no longer gets stuck. Success!
Q: Do the timestamps on the left side of the lt
output reflect actual performance in a non-debugging session?
A: No. The debugger inserts additional special-purpose debug nodes to the graph to record the values of intermediate tensors. These nodes certainly slow down the graph execution. If you are interested in profiling your model, check out tfprof and other profiling tools for TensorFlow.
Q: How do I link tfdbg against my Session
in Bazel?
A: In your BUILD rule, declare the dependency: "//tensorflow:tensorflow_py"
. In your Python file, add:
from tensorflow.python import debug as tf_debug# Then wrap your TensorFlow Session with the local-CLI wrapper.sess = tf_debug.LocalCLIDebugWrapperSession(sess)
Q: Can I use tfdbg
if I am using tf-learn Estimators, instead of managing my own Session
objects?
A: Currently, tfdbg
can only debug the fit()
method of tf-learn Estimators. Support for debugging evaluate()
will come soon. To debug Estimator.fit()
, create a monitor and supply it as an argument. For example:
from tensorflow.python import debug as tf_debug# Create a local CLI debug hook and use it as a monitor when calling fit().classifier.fit(x=training_set.data, y=training_set.target, steps=1000, monitors=[tf_debug.LocalCLIDebugHook()])
For a detailed example based on tf-learn's iris tutorial, run:
bazel build -c opt tensorflow/python/debug:debug_tflearn_iris && \
bazel-bin/tensorflow/python/debug/debug_tflearn_iris
Q: Does tfdbg help debugging runtime errors such as shape mismatches?
A: Yes. tfdbg intercepts errors generated by ops during runtime and presents the errors with some debug instructions to the user in the CLI. See examples:
# Debugging shape mismatch during matrix multiplication.
bazel build -c opt tensorflow/python/debug:debug_errors && \
bazel-bin/tensorflow/python/debug/debug_errors \
-error shape_mismatch --debug
# Debugging uninitialized variable.
bazel build -c opt tensorflow/python/debug:debug_errors && \
bazel-bin/tensorflow/python/debug/debug_errors \
-error uninitialized_variable --debug
本文由zdx3578推荐。