def testCallingEnableTracingTwiceWithDifferentDumpRootsOverwrites(self):
dumping_callback.enable_dumping(self.dump_root)
new_dump_root = self.dump_root + "_new_dump_root"
writer = dumping_callback.enable_dumping(new_dump_root)
x = constant_op.constant([10.0, 12.0, 10.0])
for _ in range(2):
array_ops.unique(x)
writer.FlushNonExecutionFiles()
writer.FlushExecutionFiles()
reader = debug_events_reader.DebugEventsDir(new_dump_root)
execution_iter = reader.execution_iterator()
for _ in range(2):
debug_event = next(execution_iter)
self.assertGreater(debug_event.wall_time, 0)
execution = debug_event.execution
self.assertEqual(execution.op_type, "Unique")
self.assertEqual(execution.num_outputs, 2)
self.assertTrue(execution.code_location)
with self.assertRaises(StopIteration):
next(execution_iter)
old_dump_root_reader = debug_events_reader.DebugEventsDir(
self.dump_root)
execution_iter = old_dump_root_reader.execution_iterator()
# The old dump root shouldn't have been written to.
with self.assertRaises(StopIteration):
next(execution_iter)
def _readAndCheckMetadataFile(self):
"""Read and check the .metadata debug-events file."""
reader = debug_events_reader.DebugEventsDir(self.dump_root)
metadata_iter = reader.metadata_iterator()
metadata = next(metadata_iter).debug_metadata
self.assertEqual(metadata.tensorflow_version, versions.__version__)
self.assertTrue(metadata.file_version.startswith("debug.Event"))
def _readAndCheckGraphsFile(self, stack_frame_by_id):
"""Read and verify the content of the .graphs debug-event file.
Args:
stack_frame_by_id: A dict mapping unique string IDs to stack frames.
It is used by this method to look up stack frames.
Returns:
context_ids: IDs of op creation contexts (e.g., TensorFlow graphs), as a
`list` of `str`s.
op_types: Types of the ops that are created, as a `list` of `str`s with
the same length as `context_ids`.
op_name_to_op_type: A `dict` mapping op name to op type.
"""
reader = debug_events_reader.DebugEventsDir(self.dump_root)
graphs_iter = reader.graphs_iterator()
prev_wall_time = 0
op_types = []
op_name_to_op_type = dict()
context_ids = set()
for debug_event in graphs_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
graph_op_creation = debug_event.graph_op_creation
self.assertTrue(graph_op_creation.op_type)
op_types.append(graph_op_creation.op_type)
self.assertTrue(graph_op_creation.op_name)
op_name_to_op_type[
graph_op_creation.op_name] = graph_op_creation.op_type
self.assertTrue(graph_op_creation.graph_id)
context_ids.add(graph_op_creation.graph_id)
self.assertTrue(graph_op_creation.code_location)
for stack_frame_id in graph_op_creation.code_location.stack_frame_ids:
self.assertIn(stack_frame_id, stack_frame_by_id)
return context_ids, op_types, op_name_to_op_type
def _readAndCheckGraphExecutionTracesFile(self, context_ids):
"""Read & verify the content of the .graph_execution_trace debug-event file.
Args:
context_ids: Op-creation context IDs from _readAndCheckGraphsFile().
Returns:
op_names: Names of the ops that are executed, as a `list` of `str`s.
output_slots: Output slots, as a `list` of `int`s, with the same length as
`op_names`. In other words, for an executed op with N output tensors,
there will be N entries in this `list` and in `op_names`, at
corresponding indices.
tensor_values: Tensor values or their concise summaries, depending on
TensorDebugMode.
"""
reader = debug_events_reader.DebugEventsDir(self.dump_root)
graph_execution_traces_iter = reader.graph_execution_traces_iterator()
op_names = []
output_slots = []
tensor_values = []
for debug_event in graph_execution_traces_iter:
self.assertGreaterEqual(debug_event.wall_time, 0)
graph_execution_trace = debug_event.graph_execution_trace
op_names.append(graph_execution_trace.op_name)
# All the ops in the graph have only one output.
self.assertTrue(graph_execution_trace.tfdbg_context_id)
self.assertIn(graph_execution_trace.tfdbg_context_id, context_ids)
output_slots.append(graph_execution_trace.output_slot)
# Under the default NO_TENSOR tensor-debug mode, the tensor_proto ought to
# be an empty float32 tensor.
tensor_values.append(
tensor_util.MakeNdarray(graph_execution_trace.tensor_proto))
return op_names, output_slots, tensor_values
def _readAndCheckExecutionFile(self):
"""Read and verify the content of the .execution debug-event file.
Returns:
executed_op_types: Types of ops that are created, as a `list` of `str`.
input_tensor_ids: Input tensor IDs for each of the ops executed, as a
`list` of `list` of `int`s, with the same length as `executed_op_types`.
output_tensor_ids: Output tensor IDs for each of the ops executed, as a
`list` of `list` of `int`s, with the same length as `executed_op_types`.
tensor_debug_modes: Tensor debug modes used to instrument each of ops
executed.
"""
reader = debug_events_reader.DebugEventsDir(self.dump_root)
execution_iter = reader.execution_iterator()
prev_wall_time = 1
executed_op_types = []
input_tensor_ids = []
output_tensor_ids = []
tensor_debug_modes = []
for debug_event in execution_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
execution = debug_event.execution
executed_op_types.append(execution.op_type)
input_tensor_ids.append(execution.input_tensor_ids)
output_tensor_ids.append(execution.output_tensor_ids)
tensor_debug_modes.append(execution.tensor_debug_mode)
# TODO(cais): When tensor debug modes other than NO_TENSOR is supported,
# return tensor_values as well.
return (executed_op_types, input_tensor_ids, output_tensor_ids,
tensor_debug_modes)
def testMultiThreadedExecution(self, tensor_debug_mode):
writer = dumping_callback.enable_dumping(
self.dump_root, tensor_debug_mode=tensor_debug_mode)
x = variables.Variable(10.0, dtype=dtypes.float32)
y = variables.Variable(3.0, dtype=dtypes.float32)
@def_function.function
def increase_x():
return x.assign_add(y * 2.0)
increase_x()
num_threads = 3
threads = []
for _ in range(num_threads):
threads.append(threading.Thread(target=increase_x))
for thread in threads:
thread.start()
for thread in threads:
thread.join()
# 10 --> 16 --> 22 --> 28 --> 34.
self.assertAllClose(x.read_value(), 34.0)
writer.FlushNonExecutionFiles()
writer.FlushExecutionFiles()
stack_frame_by_id = self._readAndCheckSourceFilesAndStackFrames()
reader = debug_events_reader.DebugEventsDir(self.dump_root)
execution_iter = reader.execution_iterator()
prev_wall_time = 1
for debug_event in execution_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
(context_ids, _,
op_name_to_op_type) = self._readAndCheckGraphsFile(stack_frame_by_id)
(op_names, _, output_slots, tensor_values
) = self._readAndCheckGraphExecutionTracesFile(context_ids)
executed_op_types = [
op_name_to_op_type[op_name] for op_name in op_names
]
self.assertEqual(executed_op_types.count("Mul"), 1 + num_threads)
self.assertEqual(executed_op_types.count("ReadVariableOp"),
2 * (1 + num_threads))
for output_slot in output_slots:
self.assertEqual(output_slot, 0)
if tensor_debug_mode == "NO_TENSOR":
for tensor_value in tensor_values:
self.assertEqual(tensor_value.dtype, np.float32)
self.assertEqual(tensor_value.shape, (0, ))
elif tensor_debug_mode == "FULL_TENSOR":
mul_values = [
tensor_values[i] for i, op_type in enumerate(executed_op_types)
if op_type == "Mul"
]
self.assertAllClose(mul_values, [6.0, 6.0, 6.0, 6.0])
def _readAndCheckSourceFilesAndStackFrames(self):
"""Read and verify the .source_files & .stack_frames debug-event files.
Returns:
A dict mapping stack frame IDs to stack frames (FileLineCol).
"""
reader = debug_events_reader.DebugEventsDir(self.dump_root)
# Check the content of the .source_files file.
source_files_iter = reader.source_files_iterator()
source_file_paths = []
prev_wall_time = 1
for debug_event in source_files_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
source_file = debug_event.source_file
self.assertEqual(source_file.host_name, socket.gethostname())
self.assertTrue(source_file.file_path)
if source_file.lines:
self.assertTrue(os.path.isfile(source_file.file_path))
source_file_paths.append(source_file.file_path)
# Assert the file paths are unique.
self.assertEqual(len(source_file_paths), len(set(source_file_paths)))
# Check the content of the .stack_frames file.
stack_frame_by_id = dict() # A map from ID to stack frame.
stack_frames_iter = reader.stack_frames_iterator()
prev_wall_time = 0
for debug_event in stack_frames_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
stack_frame_with_id = debug_event.stack_frame_with_id
stack_frame_id = stack_frame_with_id.id
file_line_col = stack_frame_with_id.file_line_col
self.assertTrue(stack_frame_id)
self.assertNotIn(stack_frame_id, stack_frame_by_id,
"Duplicate stack frame ID: %s" % id)
stack_frame_by_id[stack_frame_id] = (file_line_col.file_index,
file_line_col.line,
file_line_col.func)
self.assertGreaterEqual(file_line_col.file_index, 0)
self.assertLess(file_line_col.file_index, len(source_file_paths))
self.assertTrue(file_line_col.line) # Line numbers are 1-based.
self.assertTrue(file_line_col.func)
# Assert the stack frames are unique.
self.assertEqual(len(stack_frame_by_id.values()),
len(set(stack_frame_by_id.values())))
return stack_frame_by_id
def testCallingEnableTracingTwiceWithTheSameDumpRootIsIdempotent(self):
dumping_callback.enable_dumping(self.dump_root)
writer = dumping_callback.enable_dumping(self.dump_root)
x = constant_op.constant([10.0, 12.0, 10.0])
for _ in range(2):
array_ops.unique(x)
writer.FlushNonExecutionFiles()
writer.FlushExecutionFiles()
reader = debug_events_reader.DebugEventsDir(self.dump_root)
execution_iter = reader.execution_iterator()
for _ in range(2):
debug_event = next(execution_iter)
self.assertGreater(debug_event.wall_time, 0)
execution = debug_event.execution
self.assertEqual(execution.op_type, "Unique")
self.assertEqual(execution.num_outputs, 2)
self.assertTrue(execution.code_location)
with self.assertRaises(StopIteration):
next(execution_iter)
def testDisableTracingWorks(self):
writer = dumping_callback.enable_dumping(self.dump_root)
dumping_callback.disable_dumping()
x = constant_op.constant([10.0, 12.0, 10.0])
for _ in range(2):
array_ops.unique(x)
writer.FlushNonExecutionFiles()
writer.FlushExecutionFiles()
reader = debug_events_reader.DebugEventsDir(self.dump_root)
source_files_iter = reader.source_files_iterator()
stack_frames_iter = reader.stack_frames_iterator()
execution_iter = reader.execution_iterator()
# No source-file, stack-frame or execution data should have been dumped.
with self.assertRaises(StopIteration):
next(source_files_iter)
with self.assertRaises(StopIteration):
next(stack_frames_iter)
with self.assertRaises(StopIteration):
next(execution_iter)
def testPureEagerOpExecution(self, tensor_debug_mode):
"""Test catching Infinity in eager op execution: float32."""
writer = dumping_callback.enable_dumping(
self.dump_root, tensor_debug_mode=tensor_debug_mode)
x = constant_op.constant(10.0)
zero = constant_op.constant(0.0)
one = constant_op.constant(1.0)
two = constant_op.constant(2.0)
three = constant_op.constant(3.0)
# Use Collatz conjecture as a test case.
while x > one:
if math_ops.equal(x % two, zero):
x = x / two
else:
x = x * three + one
writer.FlushNonExecutionFiles()
self._readAndCheckMetadataFile()
stack_frame_by_id = self._readAndCheckSourceFilesAndStackFrames()
# Before FlushExecutionFiles() is called, the .execution file should be
# empty.
reader = debug_events_reader.DebugEventsDir(self.dump_root)
execution_iter = reader.execution_iterator()
with self.assertRaises(StopIteration):
next(execution_iter)
# After the flushing, the .execution file should hold the appropriate
# contents.
writer.FlushExecutionFiles()
execution_iter = reader.execution_iterator()
prev_wall_time = 1
executed_op_types = []
tensor_values = collections.defaultdict(lambda: [])
for debug_event in execution_iter:
self.assertGreaterEqual(debug_event.wall_time, prev_wall_time)
prev_wall_time = debug_event.wall_time
execution = debug_event.execution
executed_op_types.append(execution.op_type)
self.assertTrue(execution.input_tensor_ids)
self.assertTrue(execution.output_tensor_ids)
if tensor_debug_mode == "NO_TENSOR":
# Due to the NO_TENSOR tensor debug mode, tensor_protos ought to
# be empty.
self.assertFalse(execution.tensor_protos)
elif tensor_debug_mode == "FULL_TENSOR":
# Under the FULL_TENSOR mode, the value of the tensor should be
# available through `tensor_protos`.
tensor_value = float(
tensor_util.MakeNdarray(execution.tensor_protos[0]))
tensor_values[execution.op_type].append(tensor_value)
# Verify the code_location field.
self.assertTrue(execution.code_location.stack_frame_ids)
for stack_frame_id in execution.code_location.stack_frame_ids:
self.assertIn(stack_frame_id, stack_frame_by_id)
if tensor_debug_mode == "FULL_TENSOR":
self.assertAllClose(tensor_values["Greater"],
[1, 1, 1, 1, 1, 1, 0])
self.assertAllClose(tensor_values["RealDiv"], [5, 8, 4, 2, 1])
self.assertAllClose(tensor_values["Mul"], [15])
self.assertAllClose(tensor_values["AddV2"], [16])
self.assertEqual(
executed_op_types,
[
"Greater",
"FloorMod",
"Equal",
"RealDiv", # 10 --> 5
"Greater",
"FloorMod",
"Equal",
"Mul",
"AddV2", # 5 --> 16
"Greater",
"FloorMod",
"Equal",
"RealDiv", # 16 --> 8
"Greater",
"FloorMod",
"Equal",
"RealDiv", # 8 --> 4
"Greater",
"FloorMod",
"Equal",
"RealDiv", # 4 --> 2
"Greater",
"FloorMod",
"Equal",
"RealDiv", # 2 --> 1
"Greater"
])
# Due to the pure eager op execution, the .graph file and the
# .graph_execution_traces file ought to be empty.
graphs_iterator = reader.graphs_iterator()
with self.assertRaises(StopIteration):
next(graphs_iterator)
graph_trace_iter = reader.graph_execution_traces_iterator()
with self.assertRaises(StopIteration):
next(graph_trace_iter)
def testFunctionExecutionWithControlFlow(self, tensor_debug_mode):
writer = dumping_callback.enable_dumping(
self.dump_root, tensor_debug_mode=tensor_debug_mode)
@def_function.function
def iterative_doubling(x, times):
i = constant_op.constant(0, dtype=dtypes.int32)
while i < times:
x = x * 2.0
i += 1
return x
x = constant_op.constant(0.5, dtype=dtypes.float32)
times = constant_op.constant(4, dtype=dtypes.int32)
self.assertAllClose(self.evaluate(iterative_doubling(x, times)), 8.0)
writer.FlushNonExecutionFiles()
stack_frame_by_id = self._readAndCheckSourceFilesAndStackFrames()
# Verify the content of the .graphs file.
context_ids, op_types, op_name_to_op_type = (
self._readAndCheckGraphsFile(stack_frame_by_id))
self.assertIn("Less", op_types)
self.assertIn("Mul", op_types)
self.assertIn("AddV2", op_types)
# Before FlushExecutionFiles() is called, the .execution and
# .graph_execution_traces files should be both empty.
reader = debug_events_reader.DebugEventsDir(self.dump_root)
execution_iter = reader.execution_iterator()
graph_execution_traces_iter = reader.graph_execution_traces_iterator()
with self.assertRaises(StopIteration):
next(execution_iter)
with self.assertRaises(StopIteration):
next(graph_execution_traces_iter)
# TODO(cais): Backport execution instrumentation to tf.Session.
writer.FlushExecutionFiles()
# After the flushing, the .execution file should hold the appropriate
# contents.
if context.executing_eagerly():
(executed_op_types, input_tensor_ids, output_tensor_ids,
tensor_debug_modes,
tensor_values) = self._readAndCheckExecutionFile()
# NOTE(b/142486213): Execution of the TF function happens with
# Session.run() in v1 graph mode, hence it doesn't get logged to the
# .execution file.
self.assertLen(executed_op_types, 1)
self.assertIn("iterative_doubling", executed_op_types[0])
self.assertLen(input_tensor_ids[0], 2)
self.assertLen(output_tensor_ids[0], 1)
self.assertEqual(
tensor_debug_modes[0],
debug_event_pb2.TensorDebugMode.Value(tensor_debug_mode))
if tensor_debug_mode == "FULL_TENSOR":
self.assertAllClose(tensor_values, [[8.0]])
(op_names, _, output_slots, tensor_values
) = self._readAndCheckGraphExecutionTracesFile(context_ids)
executed_op_types = [
op_name_to_op_type[op_name] for op_name in op_names
]
# The Less op should have been executed 5 times.
self.assertEqual(executed_op_types.count("Less"), 5)
# The last executed op should be Less.
self.assertEqual(executed_op_types[-1], "Less")
# The Mul op should have been executed 4 times.
self.assertEqual(executed_op_types.count("Mul"), 4)
# The AddV2 op should have been run, but we refrain from asserting on how
# many times it's executed.
self.assertIn("AddV2", executed_op_types)
for output_slot in output_slots:
self.assertEqual(output_slot, 0)
if tensor_debug_mode == "NO_TENSOR":
# Under the default NO_TENSOR tensor-debug mode, the tensor_proto ought to
# be an empty float32 tensor.
for tensor_value in tensor_values:
self.assertEqual(tensor_value.dtype, np.float32)
self.assertEqual(tensor_value.shape, (0, ))
elif tensor_debug_mode == "FULL_TENSOR":
less_values = [
tensor_values[i] for i, op_type in enumerate(executed_op_types)
if op_type == "Less"
]
self.assertAllClose(less_values, [True, True, True, True, False])
mul_values = [
tensor_values[i] for i, op_type in enumerate(executed_op_types)
if op_type == "Mul"
]
self.assertAllClose(mul_values, [1.0, 2.0, 4.0, 8.0])
