pytorch

2eba82d1 - [dynamo] decrease logging level for graph break in higher order op. (#119079)

[dynamo] decrease logging level for graph break in higher order op. (#119079) Fixes https://github.com/pytorch/pytorch/issues/119059. This hides both logs behind TORCH_LOGS=dynamo. Just logging the exception seems not very informative. So I just put both under log.info(). For the example in the issue the log now looks like: ``` (pytorch-3.10) ~/local/pytorch$ python test.py (pytorch-3.10) ~/local/pytorch$ ``` ``` (pytorch-3.10) ~/local/pytorch$ python test.py (pytorch-3.10) ~/local/pytorch$ TORCH_LOGS=dynamo python test.py [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] Step 1: torchdynamo start tracing linear /home/yidi/local/pytorch/test.py:267 [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] Stack (most recent call last): [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/test.py", line 272, in <module> [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] y = linear(x) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 453, in _fn [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 615, in catch_errors [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] return callback(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 748, in _convert_frame [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] result = inner_convert(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 390, in _convert_frame_assert [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] return _compile( [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/miniconda3/envs/pytorch-3.10/lib/python3.10/contextlib.py", line 79, in inner [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] return func(*args, **kwds) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 650, in _compile [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] guarded_code = compile_inner(code, one_graph, hooks, transform) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/utils.py", line 248, in time_wrapper [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] r = func(*args, **kwargs) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 531, in compile_inner [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] out_code = transform_code_object(code, transform) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/bytecode_transformation.py", line 1033, in transform_code_object [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] transformations(instructions, code_options) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 155, in _fn [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 478, in transform [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] tracer = InstructionTranslator( [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/symbolic_convert.py", line 2032, in __init__ [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] _step_logger()( [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/logging.py", line 55, in log [2024-02-02 14:08:19,000] [0/0] torch._dynamo.symbolic_convert: [INFO] logger.log(level, "Step %s: %s", step, msg, **kwargs) [2024-02-02 14:08:19,001] [0/0] torch.fx.experimental.symbolic_shapes: [INFO] create_env [2024-02-02 14:08:19,016] [0/0] torch._dynamo.variables.higher_order_ops: [INFO] speculate_subgraph: while introspecting autograd.Function, we were unable to trace function `backward` into a single graph. This means that Dynamo was unable to prove safety for this API and will fall back to eager-mode PyTorch, which could lead to a slowdown. [2024-02-02 14:08:19,016] [0/0] torch._dynamo.variables.higher_order_ops: [INFO] call_method GetAttrVariable(AutogradFunctionContextVariable(Function), needs_input_grad) __getitem__ (ConstantVariable(int),) {} [2024-02-02 14:08:19,017] [0/0] torch._dynamo.convert_frame: [INFO] Restarting analysis due to _dynamo/symbolic_convert.py:141 in fail_and_restart_analysis [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] Step 1: torchdynamo start tracing linear /home/yidi/local/pytorch/test.py:267 [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] Stack (most recent call last): [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/test.py", line 272, in <module> [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] y = linear(x) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 453, in _fn [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 615, in catch_errors [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] return callback(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 748, in _convert_frame [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] result = inner_convert(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 390, in _convert_frame_assert [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] return _compile( [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/miniconda3/envs/pytorch-3.10/lib/python3.10/contextlib.py", line 79, in inner [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] return func(*args, **kwds) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 650, in _compile [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] guarded_code = compile_inner(code, one_graph, hooks, transform) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/utils.py", line 248, in time_wrapper [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] r = func(*args, **kwargs) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 531, in compile_inner [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] out_code = transform_code_object(code, transform) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/bytecode_transformation.py", line 1033, in transform_code_object [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] transformations(instructions, code_options) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 155, in _fn [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 478, in transform [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] tracer = InstructionTranslator( [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/symbolic_convert.py", line 2032, in __init__ [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] _step_logger()( [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/logging.py", line 55, in log [2024-02-02 14:08:19,017] [0/0_1] torch._dynamo.symbolic_convert: [INFO] logger.log(level, "Step %s: %s", step, msg, **kwargs) [2024-02-02 14:08:19,017] [0/0_1] torch.fx.experimental.symbolic_shapes: [INFO] create_env [2024-02-02 14:08:19,021] [0/0_1] torch.fx.experimental.symbolic_shapes: [INFO] produce_guards [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] Step 1: torchdynamo start tracing forward /home/yidi/local/pytorch/test.py:257 [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] Stack (most recent call last): [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/test.py", line 272, in <module> [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] y = linear(x) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 453, in _fn [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/test.py", line 268, in linear [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return UseNeedsInputGradFunction.apply(x) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/autograd/function.py", line 572, in apply [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return super().apply(*args, **kwargs) # type: ignore[misc] [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/eval_frame.py", line 615, in catch_errors [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return callback(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 748, in _convert_frame [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] result = inner_convert(frame, cache_entry, hooks, frame_state) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 390, in _convert_frame_assert [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return _compile( [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/miniconda3/envs/pytorch-3.10/lib/python3.10/contextlib.py", line 79, in inner [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return func(*args, **kwds) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 650, in _compile [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] guarded_code = compile_inner(code, one_graph, hooks, transform) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/utils.py", line 248, in time_wrapper [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] r = func(*args, **kwargs) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 531, in compile_inner [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] out_code = transform_code_object(code, transform) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/bytecode_transformation.py", line 1033, in transform_code_object [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] transformations(instructions, code_options) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 155, in _fn [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] return fn(*args, **kwargs) [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/convert_frame.py", line 478, in transform [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] tracer = InstructionTranslator( [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/symbolic_convert.py", line 2032, in __init__ [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] _step_logger()( [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] File "/home/yidi/local/pytorch/torch/_dynamo/logging.py", line 55, in log [2024-02-02 14:08:19,025] [1/0] torch._dynamo.symbolic_convert: [INFO] logger.log(level, "Step %s: %s", step, msg, **kwargs) [2024-02-02 14:08:19,025] [1/0] torch.fx.experimental.symbolic_shapes: [INFO] create_env [2024-02-02 14:08:19,097] torch._dynamo.utils: [INFO] TorchDynamo compilation metrics: [2024-02-02 14:08:19,097] torch._dynamo.utils: [INFO] Function, Runtimes (s) [2024-02-02 14:08:19,097] torch._dynamo.utils: [INFO] _compile.<locals>.compile_inner, 0.0283 ``` Pull Request resolved: https://github.com/pytorch/pytorch/pull/119079 Approved by: https://github.com/zou3519